niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #250
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.06s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96--- PASS: TestShellSplit (0.00s)97=== CONT TestScriptTokenNoExpiryRerunsEveryCall98=== CONT TestSetClientTLSErrors99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestStreamPushBatchesUnderLoad102=== CONT TestScriptTokenScriptFails103=== CONT TestScriptTokenBadJSON104=== CONT TestScriptTokenEmptyToken105=== CONT TestScriptTokenCachesUntilRefresh106=== CONT TestStreamPushGivesUpOnDeadServer107=== CONT TestStreamPushIsolatesFailures1082026/09/22 10:48:33 ERROR Upload failed error="connection refused" count=201092026/09/22 10:48:33 ERROR Server seems unavailable, giving up on batch untried=171102026/09/22 10:48:33 ERROR Upload failed error="bad path" count=3111--- PASS: TestStreamPushIsolatesFailures (0.00s)112--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)113=== CONT TestStreamPushReportsEveryPath114=== RUN TestSetClientTLSErrors/missing_cert_file115=== PAUSE TestSetClientTLSErrors/missing_cert_file116=== RUN TestSetClientTLSErrors/missing_key_file117=== PAUSE TestSetClientTLSErrors/missing_key_file118=== RUN TestSetClientTLSErrors/missing_ca_file119=== PAUSE TestSetClientTLSErrors/missing_ca_file120=== CONT TestShellSplitErrors121=== RUN TestSetClientTLSErrors/invalid_ca_file122=== PAUSE TestSetClientTLSErrors/invalid_ca_file123=== CONT TestFileTokenEmpty124--- PASS: TestShellSplitErrors (0.00s)125=== CONT TestFileTokenMissing126--- PASS: TestStreamPushReportsEveryPath (0.00s)127=== CONT TestEncodeNixBase32WithRealHash128--- PASS: TestEncodeNixBase32WithRealHash (0.00s)129=== CONT TestDoWithRetry_BodyReplayedViaGetBody130--- PASS: TestFileTokenMissing (0.00s)131=== CONT TestResolveStorePath1322026/09/22 10:48:33 WARN Rate limiter enabled after throttle name=server-test rate=51332026/09/22 10:48:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:58284134--- PASS: TestDoServerRequestAttachesToken (0.01s)135=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1362026/09/22 10:48:33 WARN Rate limiter enabled after throttle name=server-test rate=5137--- PASS: TestFileTokenEmpty (0.00s)138=== CONT TestRateLimiterFeedback139=== RUN TestRateLimiterFeedback/429_enables_limiter140=== PAUSE TestRateLimiterFeedback/429_enables_limiter141=== RUN TestRateLimiterFeedback/503_enables_limiter142=== PAUSE TestRateLimiterFeedback/503_enables_limiter1432026/09/22 10:48:33 WARN Rate limiter backed off name=server-test rate=5144=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter1452026/09/22 10:48:33 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:58284146=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter147=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter148=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter149=== CONT TestPathInfoCACompatibility150=== RUN TestPathInfoCACompatibility/null_ca_field151=== PAUSE TestPathInfoCACompatibility/null_ca_field152=== RUN TestPathInfoCACompatibility/old_string_format_-_text153=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text154=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive155=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive156=== RUN TestPathInfoCACompatibility/new_structured_format_-_text157=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text158=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method159=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method160=== CONT TestParsePathInfoJSONMultiplePaths161=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths162=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163--- PASS: TestResolveStorePath (0.00s)164=== CONT TestParsePathInfoJSON165=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths166=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths167=== RUN TestParsePathInfoJSON/Nix_format168=== PAUSE TestParsePathInfoJSON/Nix_format169=== RUN TestParsePathInfoJSON/Lix_format170=== PAUSE TestParsePathInfoJSON/Lix_format171=== RUN TestParsePathInfoJSON/empty_input172=== CONT TestPathInfoHashCompatibility173=== PAUSE TestParsePathInfoJSON/empty_input174=== RUN TestParsePathInfoJSON/whitespace_only175=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)177=== PAUSE TestParsePathInfoJSON/whitespace_only178=== RUN TestParsePathInfoJSON/invalid_JSON179=== PAUSE TestParsePathInfoJSON/invalid_JSON180=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon181--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon183=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI184=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI185=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512186=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512187=== CONT TestConvertHashToNix32188=== RUN TestConvertHashToNix32/SRI_format_to_Nix32189=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32190=== RUN TestConvertHashToNix32/already_Nix32_format191=== PAUSE TestConvertHashToNix32/already_Nix32_format192=== RUN TestConvertHashToNix32/invalid_format193=== PAUSE TestConvertHashToNix32/invalid_format194=== CONT TestGetStorePathHash195=== RUN TestGetStorePathHash/valid_store_path196=== PAUSE TestGetStorePathHash/valid_store_path197=== RUN TestGetStorePathHash/basename_without_hyphen_should_error198=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error199=== CONT TestFileTokenReadsAndCaches200=== CONT TestSetClientTLS201=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error202--- PASS: TestScriptTokenScriptFails (0.01s)203=== CONT TestSetClientTLSDoesNotMutateDefaultTransport204=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error205=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error206=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error207=== CONT TestClientSignaturesByStorePath208--- PASS: TestClientSignaturesByStorePath (0.00s)209=== CONT TestStreamPushReportsSignatures2102026/09/22 10:48:33 ERROR Upload failed error=boom count=1211--- PASS: TestStreamPushReportsSignatures (0.00s)212=== CONT TestStaticToken213--- PASS: TestStaticToken (0.00s)214=== CONT TestUploadMultipart_SupersededByPeer215=== RUN TestUploadMultipart_SupersededByPeer/exists216=== PAUSE TestUploadMultipart_SupersededByPeer/exists217=== RUN TestUploadMultipart_SupersededByPeer/missing218=== PAUSE TestUploadMultipart_SupersededByPeer/missing219=== CONT TestEncodeNixBase32220=== RUN TestEncodeNixBase32/test_string_hash221=== PAUSE TestEncodeNixBase32/test_string_hash222=== RUN TestEncodeNixBase32/empty_input223=== PAUSE TestEncodeNixBase32/empty_input224=== CONT TestDumpPathWriterError225--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)226=== CONT TestDumpPathSingleFile227--- PASS: TestFileTokenReadsAndCaches (0.00s)228=== CONT TestDumpPathMatchesNix229=== RUN TestSetClientTLS/rejects_connection_without_client_cert230=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert231=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA232=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA233=== RUN TestSetClientTLS/preserves_debug_logging_transport234=== PAUSE TestSetClientTLS/preserves_debug_logging_transport235=== CONT TestFilterOversizedClosures236=== RUN TestFilterOversizedClosures/no_limit_keeps_everything237=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything238=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped239=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== RUN TestFilterOversizedClosures/all_closures_skipped241=== PAUSE TestFilterOversizedClosures/all_closures_skipped242=== CONT TestPartSizeForNAR243=== RUN TestPartSizeForNAR/zero_stays_at_minimum244=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum245=== RUN TestPartSizeForNAR/small_stays_at_minimum246=== PAUSE TestPartSizeForNAR/small_stays_at_minimum247=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum248=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum249=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts250=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts251=== RUN TestPartSizeForNAR/1_TiB252=== PAUSE TestPartSizeForNAR/1_TiB253=== RUN TestPartSizeForNAR/5_TiB_S3_max_object254=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object255=== RUN TestPartSizeForNAR/capped_at_5_GiB256=== PAUSE TestPartSizeForNAR/capped_at_5_GiB257=== CONT TestUploadMultipart_PartsInParallel258--- PASS: TestScriptTokenBadJSON (0.01s)259=== CONT TestCaseHackSuffix260--- PASS: TestScriptTokenEmptyToken (0.02s)261=== CONT TestRegisterUploadedObjectReusesConnections262--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)263=== CONT TestStreamPushRequestLine2642026/09/22 10:48:33 ERROR Upload failed error=boom count=1265--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)266=== CONT TestSetClientTLSErrors/missing_cert_file267=== CONT TestSetClientTLSErrors/missing_ca_file268=== CONT TestSetClientTLSErrors/invalid_ca_file269=== CONT TestSetClientTLSErrors/missing_key_file270=== CONT TestRateLimiterFeedback/429_enables_limiter271--- PASS: TestSetClientTLSErrors (0.01s)272 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)273 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)274 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)275 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)2762026/09/22 10:48:33 WARN Rate limiter enabled after throttle name=server-test rate=52772026/09/22 10:48:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:583592782026/09/22 10:48:33 WARN Rate limiter backed off name=server-test rate=5279=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter281=== CONT TestRateLimiterFeedback/503_enables_limiter2822026/09/22 10:48:33 WARN Rate limiter enabled after throttle name=server-test rate=52832026/09/22 10:48:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:583652842026/09/22 10:48:33 WARN Rate limiter backed off name=server-test rate=5285--- PASS: TestRateLimiterFeedback (0.00s)286 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)287 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)288 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)289 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)290=== CONT TestPathInfoCACompatibility/null_ca_field291=== CONT TestPathInfoCACompatibility/new_structured_format_-_text292=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method293=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive294=== CONT TestPathInfoCACompatibility/old_string_format_-_text295--- PASS: TestPathInfoCACompatibility (0.00s)296 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)297 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)298 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)299 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)300 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)301=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths302=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths303--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)304 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)305 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)306=== CONT TestParsePathInfoJSON/Nix_format307=== CONT TestParsePathInfoJSON/invalid_JSON308=== CONT TestParsePathInfoJSON/whitespace_only309=== CONT TestParsePathInfoJSON/empty_input310=== CONT TestParsePathInfoJSON/Lix_format311--- PASS: TestParsePathInfoJSON (0.00s)312 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)313 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)314 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)315 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)316 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)317=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)318=== CONT TestConvertHashToNix32/SRI_format_to_Nix32319--- PASS: TestDumpPathWriterError (0.05s)320=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512321=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon322=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI323=== CONT TestConvertHashToNix32/invalid_format324--- PASS: TestPathInfoHashCompatibility (0.00s)325 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)326 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)327 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)328 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)329=== CONT TestGetStorePathHash/valid_store_path330=== CONT TestConvertHashToNix32/already_Nix32_format331--- PASS: TestConvertHashToNix32 (0.00s)332 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)333 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)334 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)335=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error336=== CONT TestGetStorePathHash/basename_without_hyphen_should_error337=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error338--- PASS: TestGetStorePathHash (0.00s)339 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)340 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)341 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)342 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)343=== CONT TestUploadMultipart_SupersededByPeer/exists344=== CONT TestEncodeNixBase32/test_string_hash345=== CONT TestUploadMultipart_SupersededByPeer/missing346--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)347=== CONT TestEncodeNixBase32/empty_input348--- PASS: TestEncodeNixBase32 (0.00s)349 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)350 --- PASS: TestEncodeNixBase32/empty_input (0.00s)351=== CONT TestSetClientTLS/rejects_connection_without_client_cert352=== CONT TestSetClientTLS/preserves_debug_logging_transport353--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)354 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)355 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)356=== CONT TestFilterOversizedClosures/no_limit_keeps_everything357=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA358=== CONT TestFilterOversizedClosures/all_closures_skipped3592026/09/22 10:48:33 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=50360=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3612026/09/22 10:48:33 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=2000362--- PASS: TestFilterOversizedClosures (0.00s)363 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)364 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)365 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)366=== CONT TestPartSizeForNAR/zero_stays_at_minimum367=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts368=== CONT TestPartSizeForNAR/capped_at_5_GiB369=== CONT TestPartSizeForNAR/1_TiB370=== CONT TestPartSizeForNAR/small_stays_at_minimum371=== CONT TestPartSizeForNAR/5_TiB_S3_max_object372=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum373--- PASS: TestPartSizeForNAR (0.00s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)376 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)377 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)378 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)379 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381--- PASS: TestStreamPushRequestLine (0.02s)3822026/09/22 10:48:33 http: TLS handshake error from 127.0.0.1:58371: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestStreamPushBatchesUnderLoad (0.10s)388--- PASS: TestCaseHackSuffix (0.12s)389--- PASS: TestDumpPathMatchesNix (0.13s)390--- PASS: TestDumpPathSingleFile (0.13s)391--- PASS: TestUploadMultipart_PartsInParallel (0.62s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld15".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-51550-1708907945/postgres2444377960/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-51550-1708907945/postgres2444377960/data -l logfile start421422/nix/var/nix/builds/nix-51550-1708907945/postgres2444377960:5432 - no response4232026-09-22 10:48:36.885 UTC [52203] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-22 10:48:36.885 UTC [52203] LOG: listening on Unix socket "/nix/var/nix/builds/nix-51550-1708907945/postgres2444377960/.s.PGSQL.5432"4252026-09-22 10:48:36.896 UTC [52210] LOG: database system was shut down at 2026-09-22 10:48:36 UTC4262026-09-22 10:48:36.897 UTC [52203] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-51550-1708907945/postgres2444377960:5432 - accepting connections428{"timestamp":"2026-09-22T10:48:37.115236Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"12b35083-4faf-4425-aa43-94cf8055a2ea","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}429{"timestamp":"2026-09-22T10:48:37.217749Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"93ec1229-d65c-4bef-a6b6-a4c13ec49b64","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestResolveDBConnectionString463=== PAUSE TestResolveDBConnectionString464=== RUN TestLeadElectsOneAndHandsOver465=== PAUSE TestLeadElectsOneAndHandsOver466=== RUN TestLeadIncumbentWinsAfterRestart4672026-09-22 10:48:37.532 UTC [52323] ERROR: relation "goose_db_version" does not exist at character 364682026-09-22 10:48:37.532 UTC [52323] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/22 10:48:37 OK 20241026095416_initial_model.sql (4.97ms)4702026/09/22 10:48:37 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)4712026/09/22 10:48:37 OK 20251218171726_add_pins.sql (2.52ms)4722026/09/22 10:48:37 OK 20260628120000_add_object_size_and_stats.sql (2.26ms)4732026/09/22 10:48:37 OK 20260905000000_add_claims.sql (2.96ms)4742026/09/22 10:48:37 OK 20260920000000_drop_claims.sql (5.23ms)4752026/09/22 10:48:37 goose: successfully migrated database to version: 202609200000004762026/09/22 10:48:37 OK 1_commit_pending_closure.sql (8.62ms)4772026/09/22 10:48:37 OK 2_object_stats_trigger.sql (6.03ms)4782026/09/22 10:48:37 goose: up to current file version: 24792026/09/22 10:48:37 INFO lead: acquired remote=192.0.2.1:12344802026/09/22 10:48:38 INFO lead: released remote=192.0.2.1:12344812026/09/22 10:48:38 INFO lead: acquired remote=192.0.2.1:12344822026/09/22 10:48:38 INFO lead: released remote=192.0.2.1:1234483--- PASS: TestLeadIncumbentWinsAfterRestart (1.01s)484=== RUN TestLeadEndsOnShutdown485=== PAUSE TestLeadEndsOnShutdown486=== RUN TestGCAdvisoryLockBlocksConcurrentRun4872026-09-22 10:48:38.387 UTC [52371] ERROR: relation "goose_db_version" does not exist at character 364882026-09-22 10:48:38.387 UTC [52371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4892026/09/22 10:48:38 OK 20241026095416_initial_model.sql (6.27ms)4902026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (831.67µs)4912026/09/22 10:48:38 OK 20251218171726_add_pins.sql (2.14ms)4922026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (2.13ms)4932026/09/22 10:48:38 OK 20260905000000_add_claims.sql (2.36ms)4942026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (1.17ms)4952026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000004962026/09/22 10:48:38 OK 1_commit_pending_closure.sql (1.65ms)4972026/09/22 10:48:38 OK 2_object_stats_trigger.sql (425.33µs)4982026/09/22 10:48:38 goose: up to current file version: 2499--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.17s)500=== RUN TestGCBugBareHashReferences501=== PAUSE TestGCBugBareHashReferences502=== RUN TestGCMetrics503=== PAUSE TestGCMetrics504=== RUN TestGCTaskStore_StartNew505=== PAUSE TestGCTaskStore_StartNew506=== RUN TestGCTaskStore_DeduplicateSameParams507=== PAUSE TestGCTaskStore_DeduplicateSameParams508=== RUN TestGCTaskStore_ConflictDifferentParams509=== PAUSE TestGCTaskStore_ConflictDifferentParams510=== RUN TestGCTaskStore_GetEmpty511=== PAUSE TestGCTaskStore_GetEmpty512=== RUN TestGCTaskStore_GetReturnsLatest513=== PAUSE TestGCTaskStore_GetReturnsLatest514=== RUN TestGCTaskStore_CompletedAllowsNewTask515=== PAUSE TestGCTaskStore_CompletedAllowsNewTask516=== RUN TestGCTaskStore_PhaseUpdates517=== PAUSE TestGCTaskStore_PhaseUpdates518=== RUN TestGCTaskStore_Fail519=== PAUSE TestGCTaskStore_Fail520=== RUN TestGracefulShutdownDrainsInflight521=== PAUSE TestGracefulShutdownDrainsInflight522=== RUN TestService_healthCheckHandler523=== PAUSE TestService_healthCheckHandler524=== RUN TestService_readinessHandler525=== PAUSE TestService_readinessHandler526=== RUN TestGenerateLandingPage527=== PAUSE TestGenerateLandingPage528=== RUN TestCacheConfigHandlerMaxNarSize529=== PAUSE TestCacheConfigHandlerMaxNarSize530=== RUN TestCreatePendingClosureRejectsOversizedNAR531=== PAUSE TestCreatePendingClosureRejectsOversizedNAR532=== RUN TestNARDeduplicationMetadataUploadBug533=== PAUSE TestNARDeduplicationMetadataUploadBug534=== RUN TestMetricsInventory535=== PAUSE TestMetricsInventory536=== RUN TestService_NativeMTLS537=== PAUSE TestService_NativeMTLS538=== RUN TestServerTLSConfig539=== PAUSE TestServerTLSConfig540=== RUN TestMultipartCleanup541=== PAUSE TestMultipartCleanup542=== RUN TestObjectStatsTrigger543=== PAUSE TestObjectStatsTrigger544=== RUN TestOrphanedObjectsGC545=== PAUSE TestOrphanedObjectsGC546=== RUN TestOrphanedObjectsGCStressTest547=== PAUSE TestOrphanedObjectsGCStressTest548=== RUN TestResurrectedObjectNotDeleted549=== PAUSE TestResurrectedObjectNotDeleted550=== RUN TestCreatePin_ReservedPins551=== PAUSE TestCreatePin_ReservedPins552=== RUN TestParseSingleRange553=== PAUSE TestParseSingleRange554=== RUN TestIsValidCachePath555=== PAUSE TestIsValidCachePath556=== RUN TestReadProxyNarinfo557=== PAUSE TestReadProxyNarinfo558=== RUN TestReadProxyNarinfoAlreadyDecompressed559=== PAUSE TestReadProxyNarinfoAlreadyDecompressed560=== RUN TestReadProxyNarStreaming561=== PAUSE TestReadProxyNarStreaming562=== RUN TestReadProxy404563=== PAUSE TestReadProxy404564=== RUN TestReadProxyInvalidPath565=== PAUSE TestReadProxyInvalidPath566=== RUN TestReadProxyHead567=== PAUSE TestReadProxyHead568=== RUN TestReadProxyConditionalGet569=== PAUSE TestReadProxyConditionalGet570=== RUN TestReadProxyRootRedirectsToIndexHTML571=== PAUSE TestReadProxyRootRedirectsToIndexHTML572=== RUN TestReadProxyDisabled573=== PAUSE TestReadProxyDisabled574=== RUN TestReadRedirectNar575=== PAUSE TestReadRedirectNar576=== RUN TestReadRedirectKeepsNarinfoProxied577=== PAUSE TestReadRedirectKeepsNarinfoProxied578=== RUN TestReadProxyRangeRequest579=== PAUSE TestReadProxyRangeRequest580=== RUN TestReadRedirectUsesPublicS3URL581=== PAUSE TestReadRedirectUsesPublicS3URL582=== RUN TestRedundantMultipartUpload583=== PAUSE TestRedundantMultipartUpload584=== RUN TestCompleteMultipartUpload_ErrorButObjectExists585=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists586=== RUN TestCompletedNarNotReofferedAcrossClosures587=== PAUSE TestCompletedNarNotReofferedAcrossClosures588=== RUN TestPresignedUploadRegisteredBeforeCommit589=== PAUSE TestPresignedUploadRegisteredBeforeCommit590=== RUN TestService_Rustfstest591=== PAUSE TestService_Rustfstest592=== RUN TestParseSize593=== PAUSE TestParseSize594=== RUN TestSkippedUploadsHandler595=== PAUSE TestSkippedUploadsHandler596=== RUN TestSystemdListenerNotActivated597--- PASS: TestSystemdListenerNotActivated (0.00s)598=== RUN TestWatchdogBeatsWhenHealthy599--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)600=== RUN TestWatchdogSkipsWhenUnhealthy6012026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6022026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6032026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6042026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6052026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6062026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6072026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6082026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6092026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6102026/09/22 10:48:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"611--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)612=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle613=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle614=== RUN TestProxyWriteTimeout615=== PAUSE TestProxyWriteTimeout616=== RUN TestIsValidUploadKey617=== PAUSE TestIsValidUploadKey618=== RUN TestUploadHandlersRejectInvalidKeys619=== PAUSE TestUploadHandlersRejectInvalidKeys620=== RUN TestUploadHandlersRejectOversizedBody621=== PAUSE TestUploadHandlersRejectOversizedBody622=== RUN TestService_cleanupPendingClosuresHandler623=== PAUSE TestService_cleanupPendingClosuresHandler624=== RUN TestService_createPendingClosureHandler625=== PAUSE TestService_createPendingClosureHandler626=== RUN TestService_verifyS3Integrity627=== PAUSE TestService_verifyS3Integrity628=== RUN TestCompleteMultipartUnregistered629=== PAUSE TestCompleteMultipartUnregistered630=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT631=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT632=== CONT TestReadRedirectKeepsNarinfoProxied633=== CONT TestService_AuthMiddleware634=== CONT TestGracefulShutdownDrainsInflight635=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle636=== CONT TestPinProtectsFromGC637=== CONT TestClientSharedPathCommittedMidPush638=== CONT TestReadRedirectNar639=== CONT TestGCTaskStore_Fail640--- PASS: TestGCTaskStore_Fail (0.00s)641=== CONT TestGCTaskStore_PhaseUpdates642--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)643=== CONT TestGCTaskStore_CompletedAllowsNewTask644=== CONT TestClientWithDependencies645=== CONT TestGCTaskStore_StartNew646=== CONT TestClientIntegration6472026/09/22 10:48:38 INFO Starting HTTP server address=127.0.0.1:58421648--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)649--- PASS: TestGCTaskStore_StartNew (0.00s)650=== CONT TestClientMultipleUploads6512026/09/22 10:48:38 INFO Shutdown signal received, draining in-flight requests timeout=10s652--- PASS: TestGracefulShutdownDrainsInflight (0.07s)653=== CONT TestClientErrorHandling654=== RUN TestClientErrorHandling/InvalidStorePath655=== PAUSE TestClientErrorHandling/InvalidStorePath656=== RUN TestClientErrorHandling/InvalidAuthToken657=== PAUSE TestClientErrorHandling/InvalidAuthToken658=== RUN TestClientErrorHandling/ServerNotAvailable659=== PAUSE TestClientErrorHandling/ServerNotAvailable660=== CONT TestClientCADerivations6612026-09-22 10:48:38.970 UTC [52407] ERROR: relation "goose_db_version" does not exist at character 366622026-09-22 10:48:38.970 UTC [52407] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6632026-09-22 10:48:38.973 UTC [52408] ERROR: relation "goose_db_version" does not exist at character 366642026-09-22 10:48:38.973 UTC [52408] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-09-22 10:48:38.977 UTC [52409] ERROR: relation "goose_db_version" does not exist at character 366662026-09-22 10:48:38.977 UTC [52409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026-09-22 10:48:38.977 UTC [52410] ERROR: relation "goose_db_version" does not exist at character 366682026-09-22 10:48:38.977 UTC [52410] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6692026-09-22 10:48:38.977 UTC [52411] ERROR: relation "goose_db_version" does not exist at character 366702026-09-22 10:48:38.977 UTC [52411] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6712026-09-22 10:48:38.979 UTC [52413] ERROR: relation "goose_db_version" does not exist at character 366722026-09-22 10:48:38.979 UTC [52413] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6732026-09-22 10:48:38.980 UTC [52412] ERROR: relation "goose_db_version" does not exist at character 366742026-09-22 10:48:38.980 UTC [52412] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6752026-09-22 10:48:38.980 UTC [52415] ERROR: relation "goose_db_version" does not exist at character 366762026-09-22 10:48:38.980 UTC [52415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6772026-09-22 10:48:38.980 UTC [52414] ERROR: relation "goose_db_version" does not exist at character 366782026-09-22 10:48:38.980 UTC [52414] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6792026/09/22 10:48:38 OK 20241026095416_initial_model.sql (7.65ms)6802026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (766.54µs)6812026-09-22 10:48:38.988 UTC [52416] ERROR: relation "goose_db_version" does not exist at character 366822026-09-22 10:48:38.988 UTC [52416] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6832026/09/22 10:48:38 OK 20241026095416_initial_model.sql (7.25ms)6842026/09/22 10:48:38 OK 20241026095416_initial_model.sql (8.86ms)6852026/09/22 10:48:38 OK 20251218171726_add_pins.sql (2.75ms)6862026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (788.83µs)6872026/09/22 10:48:38 OK 20241026095416_initial_model.sql (7.97ms)6882026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (692.83µs)6892026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (611.67µs)6902026/09/22 10:48:38 OK 20241026095416_initial_model.sql (8.67ms)6912026/09/22 10:48:38 OK 20251218171726_add_pins.sql (1.45ms)6922026/09/22 10:48:38 OK 20241026095416_initial_model.sql (7.23ms)6932026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.93ms)6942026/09/22 10:48:38 OK 20241026095416_initial_model.sql (6.85ms)6952026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (1ms)6962026/09/22 10:48:38 OK 20251218171726_add_pins.sql (1.78ms)6972026/09/22 10:48:38 OK 20251218171726_add_pins.sql (1.6ms)6982026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (682.92µs)6992026/09/22 10:48:38 OK 20241026095416_initial_model.sql (7.57ms)7002026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (839.21µs)7012026/09/22 10:48:38 OK 20241026095416_initial_model.sql (9.36ms)7022026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.1ms)7032026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (658.46µs)7042026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (745.63µs)7052026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.95ms)7062026/09/22 10:48:38 OK 20251218171726_add_pins.sql (1.72ms)7072026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.56ms)7082026/09/22 10:48:38 OK 20260905000000_add_claims.sql (2.68ms)7092026/09/22 10:48:38 OK 20251218171726_add_pins.sql (1.92ms)7102026/09/22 10:48:38 OK 20260905000000_add_claims.sql (1.41ms)7112026/09/22 10:48:38 OK 20251218171726_add_pins.sql (2.42ms)7122026/09/22 10:48:38 OK 20251218171726_add_pins.sql (1.75ms)7132026/09/22 10:48:38 OK 20260905000000_add_claims.sql (1.54ms)7142026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (1.32ms)7152026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000007162026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.25ms)7172026/09/22 10:48:38 OK 20251218171726_add_pins.sql (2.47ms)7182026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (1.27ms)7192026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000007202026/09/22 10:48:38 OK 20260905000000_add_claims.sql (1.82ms)7212026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (2.37ms)7222026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.53ms)7232026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (1.42ms)7242026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000007252026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)7262026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (1.32ms)7272026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000007282026/09/22 10:48:38 OK 1_commit_pending_closure.sql (1.45ms)7292026/09/22 10:48:38 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)7302026/09/22 10:48:38 OK 1_commit_pending_closure.sql (1.57ms)7312026/09/22 10:48:38 OK 20260905000000_add_claims.sql (1.96ms)7322026/09/22 10:48:38 OK 1_commit_pending_closure.sql (1.1ms)7332026/09/22 10:48:38 OK 2_object_stats_trigger.sql (611.92µs)7342026/09/22 10:48:38 goose: up to current file version: 27352026/09/22 10:48:38 OK 2_object_stats_trigger.sql (510.33µs)7362026/09/22 10:48:38 goose: up to current file version: 27372026/09/22 10:48:38 OK 2_object_stats_trigger.sql (375.04µs)7382026/09/22 10:48:38 goose: up to current file version: 27392026/09/22 10:48:38 OK 1_commit_pending_closure.sql (945.96µs)7402026/09/22 10:48:38 OK 20260905000000_add_claims.sql (2.3ms)7412026/09/22 10:48:38 OK 20260905000000_add_claims.sql (1.96ms)7422026/09/22 10:48:38 OK 20260905000000_add_claims.sql (2.25ms)7432026/09/22 10:48:38 OK 20241026095416_initial_model.sql (6.29ms)7442026/09/22 10:48:38 OK 2_object_stats_trigger.sql (579.83µs)7452026/09/22 10:48:38 goose: up to current file version: 27462026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (1.35ms)7472026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000007482026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (1.03ms)7492026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000007502026/09/22 10:48:38 OK 20260920000000_drop_claims.sql (717.21µs)7512026/09/22 10:48:38 goose: successfully migrated database to version: 202609200000007522026/09/22 10:48:38 OK 20260905000000_add_claims.sql (2.37ms)7532026/09/22 10:48:38 OK 20251210153512_drop_unused_gin_index.sql (443.96µs)7542026/09/22 10:48:39 OK 20260920000000_drop_claims.sql (1.29ms)7552026/09/22 10:48:39 goose: successfully migrated database to version: 202609200000007562026/09/22 10:48:39 OK 1_commit_pending_closure.sql (919.21µs)7572026/09/22 10:48:39 OK 1_commit_pending_closure.sql (798.58µs)7582026/09/22 10:48:39 OK 2_object_stats_trigger.sql (251.17µs)7592026/09/22 10:48:39 goose: up to current file version: 27602026/09/22 10:48:39 OK 2_object_stats_trigger.sql (241.67µs)7612026/09/22 10:48:39 goose: up to current file version: 27622026/09/22 10:48:39 OK 20251218171726_add_pins.sql (866.83µs)7632026/09/22 10:48:39 OK 20260920000000_drop_claims.sql (1.13ms)7642026/09/22 10:48:39 goose: successfully migrated database to version: 202609200000007652026/09/22 10:48:39 OK 1_commit_pending_closure.sql (1.65ms)7662026/09/22 10:48:39 OK 2_object_stats_trigger.sql (202.17µs)7672026/09/22 10:48:39 goose: up to current file version: 27682026/09/22 10:48:39 OK 1_commit_pending_closure.sql (1.49ms)7692026/09/22 10:48:39 OK 2_object_stats_trigger.sql (211.5µs)7702026/09/22 10:48:39 goose: up to current file version: 27712026/09/22 10:48:39 OK 1_commit_pending_closure.sql (1.53ms)7722026/09/22 10:48:39 OK 2_object_stats_trigger.sql (204.54µs)7732026/09/22 10:48:39 goose: up to current file version: 27742026/09/22 10:48:39 OK 20260628120000_add_object_size_and_stats.sql (23.63ms)7752026/09/22 10:48:39 OK 20260905000000_add_claims.sql (9.74ms)7762026/09/22 10:48:39 OK 20260920000000_drop_claims.sql (7.31ms)7772026/09/22 10:48:39 goose: successfully migrated database to version: 202609200000007782026/09/22 10:48:39 OK 1_commit_pending_closure.sql (1.99ms)7792026/09/22 10:48:39 OK 2_object_stats_trigger.sql (613.25µs)7802026/09/22 10:48:39 goose: up to current file version: 2781=== NAME TestClientIntegration782 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-51550-1708907945/TestClientIntegration3277014/002/store/qfmi89hn9ph4zlmyv69vsi7xjyxf7h3m-test-file.txt7832026/09/22 10:48:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"7842026/09/22 10:48:39 INFO Received uploads request method=POST path=/api/pending_closures7852026/09/22 10:48:39 INFO Received uploads request method=POST path=/api/pending_closures7862026/09/22 10:48:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)7872026/09/22 10:48:39 INFO Uploading qfmi89hn9ph4zlmyv69vsi7xjyxf7h3m-test-file.txt (152B)7882026/09/22 10:48:39 WARN Failed to register uploaded object key=qfmi89hn9ph4zlmyv69vsi7xjyxf7h3m.ls error="server returned 404: 404 page not found\n"7892026/09/22 10:48:39 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"7902026/09/22 10:48:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign7912026/09/22 10:48:39 INFO Signed narinfos id=1 count=17922026/09/22 10:48:39 INFO Uploading 1 narinfos7932026/09/22 10:48:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7942026/09/22 10:48:39 WARN Failed to register uploaded object key=qfmi89hn9ph4zlmyv69vsi7xjyxf7h3m.narinfo error="server returned 404: 404 page not found\n"7952026/09/22 10:48:39 INFO Completed upload id=17962026/09/22 10:48:39 INFO Upload complete. (221ms)7972026/09/22 10:48:39 INFO All 1 paths already cached798 client_integration_test.go:312: Retrieved narinfo from S3:799 StorePath: /nix/var/nix/builds/nix-51550-1708907945/TestClientIntegration3277014/002/store/qfmi89hn9ph4zlmyv69vsi7xjyxf7h3m-test-file.txt800 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst801 Compression: zstd802 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1803 NarSize: 152804 References: 805 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1806 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)807 client_integration_test.go:313: Decompressed .ls content (64 bytes):808 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}809 client_integration_test.go:316: Testing garbage collection...810=== NAME TestPinProtectsFromGC811 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-51550-1708907945/TestPinProtectsFromGC3156928154/001/store/rb8qzilv5x89sypvisn35cwmkx5iq14c-pinned-file.txt812 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-51550-1708907945/TestPinProtectsFromGC3156928154/001/store/051ccjpq18085a3dd5v04b9y6jbiyxni-unpinned-file.txt8132026/09/22 10:48:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures8142026/09/22 10:48:39 INFO Garbage collection started8152026/09/22 10:48:39 INFO Aborted multipart uploads count=08162026/09/22 10:48:39 WARN Force mode enabled - objects will be deleted immediately without grace period817--- PASS: TestReadRedirectNar (0.88s)818=== CONT TestCacheStatsHandler8192026/09/22 10:48:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8202026/09/22 10:48:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8212026/09/22 10:48:39 INFO Received uploads request method=POST path=/api/pending_closures8222026/09/22 10:48:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8232026/09/22 10:48:39 INFO Uploading rb8qzilv5x89sypvisn35cwmkx5iq14c-pinned-file.txt (128B)8242026/09/22 10:48:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"825--- PASS: TestService_AuthMiddleware (1.01s)826=== CONT TestCacheConfigHandler827=== RUN TestCacheConfigHandler/full_config,_no_issuer828=== PAUSE TestCacheConfigHandler/full_config,_no_issuer829=== RUN TestCacheConfigHandler/no_cache_url_configured830=== PAUSE TestCacheConfigHandler/no_cache_url_configured831=== RUN TestCacheConfigHandler/no_signing_keys832=== PAUSE TestCacheConfigHandler/no_signing_keys833=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator834=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator835=== CONT TestService_ReadScope_PublicByDefault8362026/09/22 10:48:39 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"8372026/09/22 10:48:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8382026/09/22 10:48:39 INFO Signed narinfos id=1 count=18392026/09/22 10:48:39 INFO Uploading 1 narinfos8402026/09/22 10:48:39 WARN Failed to register uploaded object key=rb8qzilv5x89sypvisn35cwmkx5iq14c.ls error="server returned 404: 404 page not found\n"8412026/09/22 10:48:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8422026/09/22 10:48:39 WARN Failed to register uploaded object key=rb8qzilv5x89sypvisn35cwmkx5iq14c.narinfo error="server returned 404: 404 page not found\n"8432026/09/22 10:48:39 INFO Completed upload id=18442026/09/22 10:48:39 INFO Upload complete. (169ms)8452026/09/22 10:48:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8462026/09/22 10:48:39 INFO Received uploads request method=POST path=/api/pending_closures8472026/09/22 10:48:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8482026/09/22 10:48:39 INFO Uploading 051ccjpq18085a3dd5v04b9y6jbiyxni-unpinned-file.txt (128B)8492026/09/22 10:48:39 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"8502026/09/22 10:48:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8512026/09/22 10:48:39 INFO Signed narinfos id=2 count=18522026/09/22 10:48:39 WARN Failed to register uploaded object key=051ccjpq18085a3dd5v04b9y6jbiyxni.ls error="server returned 404: 404 page not found\n"8532026/09/22 10:48:39 INFO Uploading 1 narinfos8542026/09/22 10:48:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8552026/09/22 10:48:39 WARN Failed to register uploaded object key=051ccjpq18085a3dd5v04b9y6jbiyxni.narinfo error="server returned 404: 404 page not found\n"8562026/09/22 10:48:39 INFO Completed upload id=28572026/09/22 10:48:39 INFO Upload complete. (139ms)8582026/09/22 10:48:40 INFO Received create pin request method=POST path=/api/pins/myapp8592026/09/22 10:48:40 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-51550-1708907945/TestPinProtectsFromGC3156928154/001/store/rb8qzilv5x89sypvisn35cwmkx5iq14c-pinned-file.txt narinfo_key=rb8qzilv5x89sypvisn35cwmkx5iq14c.narinfo8602026/09/22 10:48:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures8612026/09/22 10:48:40 INFO Garbage collection started8622026/09/22 10:48:40 INFO Aborted multipart uploads count=08632026/09/22 10:48:40 WARN Force mode enabled - objects will be deleted immediately without grace period8642026-09-22 10:48:40.140 UTC [52518] ERROR: relation "goose_db_version" does not exist at character 368652026-09-22 10:48:40.140 UTC [52518] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8662026/09/22 10:48:40 OK 20241026095416_initial_model.sql (23.76ms)8672026/09/22 10:48:40 OK 20251210153512_drop_unused_gin_index.sql (940.54µs)8682026/09/22 10:48:40 OK 20251218171726_add_pins.sql (3.2ms)8692026/09/22 10:48:40 OK 20260628120000_add_object_size_and_stats.sql (22.88ms)8702026-09-22 10:48:40.201 UTC [52521] ERROR: relation "goose_db_version" does not exist at character 368712026-09-22 10:48:40.201 UTC [52521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026/09/22 10:48:40 OK 20260905000000_add_claims.sql (6.03ms)8732026/09/22 10:48:40 OK 20260920000000_drop_claims.sql (1.43ms)8742026/09/22 10:48:40 goose: successfully migrated database to version: 202609200000008752026/09/22 10:48:40 OK 1_commit_pending_closure.sql (1.84ms)8762026/09/22 10:48:40 OK 2_object_stats_trigger.sql (580.71µs)8772026/09/22 10:48:40 goose: up to current file version: 28782026/09/22 10:48:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8792026/09/22 10:48:40 OK 20241026095416_initial_model.sql (46.43ms)8802026/09/22 10:48:40 OK 20251210153512_drop_unused_gin_index.sql (9.02ms)8812026/09/22 10:48:40 OK 20251218171726_add_pins.sql (15.59ms)8822026/09/22 10:48:40 OK 20260628120000_add_object_size_and_stats.sql (7.69ms)8832026/09/22 10:48:40 OK 20260905000000_add_claims.sql (11.11ms)8842026/09/22 10:48:40 INFO Received uploads request method=POST path=/api/pending_closures8852026/09/22 10:48:40 OK 20260920000000_drop_claims.sql (15.34ms)8862026/09/22 10:48:40 goose: successfully migrated database to version: 202609200000008872026/09/22 10:48:40 OK 1_commit_pending_closure.sql (2.72ms)8882026/09/22 10:48:40 OK 2_object_stats_trigger.sql (689.08µs)8892026/09/22 10:48:40 goose: up to current file version: 2890=== NAME TestClientMultipleUploads891 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-51550-1708907945/TestClientMultipleUploads1177000919/001/store/56sly1h3ndd3g1ds8cwd0pgprq3viyhr-test-file-0.txt892--- PASS: TestReadRedirectKeepsNarinfoProxied (1.63s)893=== CONT TestService_RequireScope_OIDC8942026/09/22 10:48:40 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3003 objects-failed-to-delete=08952026/09/22 10:48:40 INFO Vacuumed table table=pending_closures8962026/09/22 10:48:40 INFO Vacuumed table table=pending_objects8972026/09/22 10:48:40 INFO Vacuumed table table=multipart_uploads8982026/09/22 10:48:40 INFO Vacuumed table table=closures8992026/09/22 10:48:40 INFO Vacuumed table table=objects9002026/09/22 10:48:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"901=== NAME TestClientMultipleUploads902 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-51550-1708907945/TestClientMultipleUploads1177000919/001/store/9j5j0s1nx2y894635mfa91xc8ndpgw3a-test-file-1.txt9032026/09/22 10:48:40 INFO Received uploads request method=POST path=/api/pending_closures9042026/09/22 10:48:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9052026/09/22 10:48:40 INFO Uploading 8rsgglrsxxw39y03slda7sk84xvmsycl-shared-dep (136B)906 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-51550-1708907945/TestClientMultipleUploads1177000919/001/store/rrm7bp8z2xg065gcavbrsnvq44rj5q8j-test-file-2.txt9072026/09/22 10:48:40 WARN Failed to register uploaded object key=8rsgglrsxxw39y03slda7sk84xvmsycl.ls error="server returned 404: 404 page not found\n"9082026/09/22 10:48:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9092026/09/22 10:48:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9102026/09/22 10:48:40 INFO Signed narinfos id=2 count=19112026/09/22 10:48:40 INFO Uploading 1 narinfos9122026/09/22 10:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9132026/09/22 10:48:40 WARN Failed to register uploaded object key=8rsgglrsxxw39y03slda7sk84xvmsycl.narinfo error="server returned 404: 404 page not found\n"9142026/09/22 10:48:40 INFO Completed upload id=29152026/09/22 10:48:40 INFO Upload complete. (146ms)9162026/09/22 10:48:40 INFO Received uploads request method=POST path=/api/pending_closures9172026/09/22 10:48:40 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)9182026/09/22 10:48:40 INFO Uploading 7vfd4l5yic0fqn5sp98x37xg136p5a4v-top (256B)9192026/09/22 10:48:40 INFO Uploading 8rsgglrsxxw39y03slda7sk84xvmsycl-shared-dep (136B)9202026/09/22 10:48:40 WARN Failed to register uploaded object key=7vfd4l5yic0fqn5sp98x37xg136p5a4v.ls error="server returned 404: 404 page not found\n"9212026/09/22 10:48:40 WARN Failed to register uploaded object key=nar/17q4vl06w8rwa5md6vnaq9zkqyrky4smhpb20gjzlb1k6bi12w2s.nar.zst error="server returned 404: 404 page not found\n"9222026/09/22 10:48:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9232026/09/22 10:48:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58483/oidc9242026/09/22 10:48:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9252026/09/22 10:48:40 WARN Failed to register uploaded object key=8rsgglrsxxw39y03slda7sk84xvmsycl.ls error="server returned 404: 404 page not found\n"9262026/09/22 10:48:40 INFO Signed narinfos id=1 count=19272026/09/22 10:48:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign9282026/09/22 10:48:40 INFO Signed narinfos id=3 count=19292026/09/22 10:48:40 INFO Uploading 2 narinfos9302026/09/22 10:48:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"931=== NAME TestClientWithDependencies932 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-51550-1708907945/TestClientWithDependencies2678682609/001/store/wwvq7acs52gfaldjav1d9jxgi0hrj40k-test-script9332026-09-22 10:48:40.621 UTC [52585] ERROR: relation "goose_db_version" does not exist at character 369342026-09-22 10:48:40.621 UTC [52585] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026/09/22 10:48:40 OK 20241026095416_initial_model.sql (6.88ms)9362026/09/22 10:48:40 OK 20251210153512_drop_unused_gin_index.sql (826.96µs)9372026/09/22 10:48:40 OK 20251218171726_add_pins.sql (2.3ms)9382026/09/22 10:48:40 OK 20260628120000_add_object_size_and_stats.sql (2.32ms)9392026/09/22 10:48:40 OK 20260905000000_add_claims.sql (3.12ms)9402026/09/22 10:48:40 OK 20260920000000_drop_claims.sql (1.23ms)9412026/09/22 10:48:40 goose: successfully migrated database to version: 202609200000009422026/09/22 10:48:40 OK 1_commit_pending_closure.sql (1.95ms)9432026/09/22 10:48:40 OK 2_object_stats_trigger.sql (527.58µs)9442026/09/22 10:48:40 goose: up to current file version: 29452026/09/22 10:48:40 INFO Received uploads request method=POST path=/api/pending_closures9462026/09/22 10:48:40 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/22 10:48:40 INFO Received uploads request method=POST path=/api/pending_closures9482026/09/22 10:48:40 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)9492026/09/22 10:48:40 INFO Uploading 9j5j0s1nx2y894635mfa91xc8ndpgw3a-test-file-1.txt (160B)9502026/09/22 10:48:40 INFO Uploading 56sly1h3ndd3g1ds8cwd0pgprq3viyhr-test-file-0.txt (160B)9512026/09/22 10:48:40 INFO Uploading rrm7bp8z2xg065gcavbrsnvq44rj5q8j-test-file-2.txt (160B)9522026/09/22 10:48:40 WARN Failed to register uploaded object key=7vfd4l5yic0fqn5sp98x37xg136p5a4v.narinfo error="server returned 404: 404 page not found\n"953 client_integration_test.go:615: Found 1 dependencies (including self)9542026/09/22 10:48:40 WARN Failed to register uploaded object key=56sly1h3ndd3g1ds8cwd0pgprq3viyhr.ls error="server returned 404: 404 page not found\n"9552026/09/22 10:48:40 WARN Failed to register uploaded object key=rrm7bp8z2xg065gcavbrsnvq44rj5q8j.ls error="server returned 404: 404 page not found\n"9562026/09/22 10:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete9572026/09/22 10:48:40 WARN Failed to register uploaded object key=8rsgglrsxxw39y03slda7sk84xvmsycl.narinfo error="server returned 404: 404 page not found\n"9582026/09/22 10:48:40 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"9592026/09/22 10:48:40 INFO Completed upload id=39602026/09/22 10:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9612026/09/22 10:48:40 INFO Completed upload id=19622026/09/22 10:48:40 INFO Upload complete. (486ms)963=== NAME TestClientSharedPathCommittedMidPush964 client_integration_test.go:680: Retrieved narinfo from S3:965 StorePath: /nix/var/nix/builds/nix-51550-1708907945/TestClientSharedPathCommittedMidPush1512430096/001/store/8rsgglrsxxw39y03slda7sk84xvmsycl-shared-dep966 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst967 Compression: zstd968 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82969 NarSize: 136970 References: 971 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n9722026/09/22 10:48:40 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"9732026/09/22 10:48:40 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"9742026/09/22 10:48:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9752026/09/22 10:48:40 WARN Failed to register uploaded object key=9j5j0s1nx2y894635mfa91xc8ndpgw3a.ls error="server returned 404: 404 page not found\n"9762026/09/22 10:48:40 INFO Signed narinfos id=1 count=19772026/09/22 10:48:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9782026/09/22 10:48:40 INFO Signed narinfos id=2 count=19792026/09/22 10:48:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign9802026/09/22 10:48:40 INFO Signed narinfos id=3 count=19812026/09/22 10:48:40 INFO Uploading 3 narinfos982 client_integration_test.go:680: Retrieved narinfo from S3:983 StorePath: /nix/var/nix/builds/nix-51550-1708907945/TestClientSharedPathCommittedMidPush1512430096/001/store/7vfd4l5yic0fqn5sp98x37xg136p5a4v-top984 URL: nar/17q4vl06w8rwa5md6vnaq9zkqyrky4smhpb20gjzlb1k6bi12w2s.nar.zst985 Compression: zstd986 NarHash: sha256:17q4vl06w8rwa5md6vnaq9zkqyrky4smhpb20gjzlb1k6bi12w2s987 NarSize: 256988 References: /nix/var/nix/builds/nix-51550-1708907945/TestClientSharedPathCommittedMidPush1512430096/001/store/8rsgglrsxxw39y03slda7sk84xvmsycl-shared-dep989 CA: text:sha256:108hw9zf1wn3nq65l9jzwn5v6wklpnx3pl746a4pxb1y14gxa3bq9902026/09/22 10:48:40 WARN Failed to register uploaded object key=9j5j0s1nx2y894635mfa91xc8ndpgw3a.narinfo error="server returned 404: 404 page not found\n"9912026/09/22 10:48:40 WARN Failed to register uploaded object key=56sly1h3ndd3g1ds8cwd0pgprq3viyhr.narinfo error="server returned 404: 404 page not found\n"9922026/09/22 10:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9932026/09/22 10:48:40 WARN Failed to register uploaded object key=rrm7bp8z2xg065gcavbrsnvq44rj5q8j.narinfo error="server returned 404: 404 page not found\n"994--- PASS: TestClientSharedPathCommittedMidPush (1.97s)995=== CONT TestService_AuthMiddleware_OIDC9962026/09/22 10:48:40 INFO Completed upload id=29972026/09/22 10:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete9982026/09/22 10:48:40 INFO Completed upload id=39992026/09/22 10:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10002026/09/22 10:48:40 INFO Completed upload id=110012026/09/22 10:48:40 INFO Upload complete. (176ms)1002=== NAME TestClientMultipleUploads1003 client_integration_test.go:369: Uploaded 3 paths in 220.961333ms10042026/09/22 10:48:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58493/oidc1005--- PASS: TestClientMultipleUploads (2.02s)1006=== CONT TestService_ReadAuthMiddleware1007--- PASS: TestCacheStatsHandler (1.16s)1008=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10092026/09/22 10:48:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10102026/09/22 10:48:40 INFO Received uploads request method=POST path=/api/pending_closures10112026/09/22 10:48:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10122026/09/22 10:48:40 INFO Uploading wwvq7acs52gfaldjav1d9jxgi0hrj40k-test-script (136B)10132026/09/22 10:48:40 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10142026/09/22 10:48:40 WARN Failed to register uploaded object key=wwvq7acs52gfaldjav1d9jxgi0hrj40k.ls error="server returned 404: 404 page not found\n"10152026/09/22 10:48:40 WARN Failed to register uploaded object key=log/466jpzygw8aawfd3nagcq9sz5pd0dd36-test-script.drv error="server returned 404: 404 page not found\n"10162026/09/22 10:48:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10172026/09/22 10:48:40 INFO Signed narinfos id=1 count=110182026/09/22 10:48:40 INFO Uploading 1 narinfos10192026/09/22 10:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10202026/09/22 10:48:40 WARN Failed to register uploaded object key=wwvq7acs52gfaldjav1d9jxgi0hrj40k.narinfo error="server returned 404: 404 page not found\n"10212026/09/22 10:48:40 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=010222026/09/22 10:48:40 INFO Completed upload id=110232026/09/22 10:48:40 INFO Upload complete. (128ms)1024=== NAME TestClientWithDependencies1025 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-51550-1708907945/TestClientWithDependencies2678682609/001/store) requires matching store prefix10262026/09/22 10:48:40 INFO Vacuumed table table=pending_closures10272026/09/22 10:48:40 INFO Vacuumed table table=pending_objects10282026/09/22 10:48:40 INFO Vacuumed table table=multipart_uploads10292026/09/22 10:48:40 INFO Vacuumed table table=closures10302026/09/22 10:48:40 INFO Vacuumed table table=objects1031--- PASS: TestClientWithDependencies (2.16s)1032=== CONT TestService_AuthMiddleware_MTLSProxyHeader1033--- PASS: TestService_ReadScope_PublicByDefault (1.18s)1034=== CONT TestGCMetrics1035=== NAME TestClientCADerivations1036 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-51550-1708907945/TestClientCADerivations1254381298/001/store/hlc5b2iiadkvw7nxixk2rirlcwh2cd7x-ca-test1037 client_ca_test.go:139: Found 1 dependencies (including self)1038=== RUN TestService_RequireScope_OIDC/builder_may_write1039=== PAUSE TestService_RequireScope_OIDC/builder_may_write1040=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1041=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1042=== RUN TestService_RequireScope_OIDC/ops_may_admin1043=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1044=== RUN TestService_RequireScope_OIDC/ops_may_not_write1045=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1046=== RUN TestService_RequireScope_OIDC/reader_may_not_write1047=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1048=== RUN TestService_RequireScope_OIDC/static_token_may_admin1049=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1050=== RUN TestService_RequireScope_OIDC/static_token_may_write1051=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1052=== RUN TestService_RequireScope_OIDC/reader_may_read1053=== PAUSE TestService_RequireScope_OIDC/reader_may_read1054=== RUN TestService_RequireScope_OIDC/writer_implies_read1055=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1056=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1057=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1058=== CONT TestGCBugBareHashReferences10592026/09/22 10:48:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10602026/09/22 10:48:41 INFO Received uploads request method=POST path=/api/pending_closures10612026/09/22 10:48:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10622026/09/22 10:48:41 INFO Uploading hlc5b2iiadkvw7nxixk2rirlcwh2cd7x-ca-test (144B)10632026/09/22 10:48:41 WARN Failed to register uploaded object key=log/38j4l3vsjw6xnqkzf31ks8xq6snmg06z-ca-test.drv error="server returned 404: 404 page not found\n"10642026/09/22 10:48:41 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"10652026/09/22 10:48:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10662026/09/22 10:48:41 WARN Failed to register uploaded object key=hlc5b2iiadkvw7nxixk2rirlcwh2cd7x.ls error="server returned 404: 404 page not found\n"10672026/09/22 10:48:41 INFO Signed narinfos id=1 count=110682026/09/22 10:48:41 INFO Uploading 1 narinfos10692026/09/22 10:48:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10702026/09/22 10:48:41 WARN Failed to register uploaded object key=hlc5b2iiadkvw7nxixk2rirlcwh2cd7x.narinfo error="server returned 404: 404 page not found\n"10712026/09/22 10:48:41 INFO Completed upload id=110722026/09/22 10:48:41 INFO Upload complete. (171ms)1073=== NAME TestClientCADerivations1074 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-51550-1708907945/TestClientCADerivations1254381298/001/store/hlc5b2iiadkvw7nxixk2rirlcwh2cd7x-ca-test1075 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1076 Compression: zstd1077 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1078 NarSize: 1441079 References: 1080 Deriver: /nix/var/nix/builds/nix-51550-1708907945/TestClientCADerivations1254381298/001/store/38j4l3vsjw6xnqkzf31ks8xq6snmg06z-ca-test.drv1081 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1082 client_ca_test.go:185: Checking for realisation files in S3...1083 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1084 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1085 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket12?endpoint=http://localhost:58397®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-51550-1708907945/TestClientCADerivations1254381298/001/store'1086 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11087--- PASS: TestClientCADerivations (2.54s)1088=== CONT TestLeadEndsOnShutdown10892026-09-22 10:48:41.346 UTC [52723] ERROR: relation "goose_db_version" does not exist at character 3610902026-09-22 10:48:41.346 UTC [52723] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026-09-22 10:48:41.347 UTC [52724] ERROR: relation "goose_db_version" does not exist at character 3610922026-09-22 10:48:41.347 UTC [52724] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026-09-22 10:48:41.352 UTC [52725] ERROR: relation "goose_db_version" does not exist at character 3610942026-09-22 10:48:41.352 UTC [52725] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10952026/09/22 10:48:41 OK 20241026095416_initial_model.sql (7.2ms)10962026/09/22 10:48:41 OK 20251210153512_drop_unused_gin_index.sql (689.79µs)10972026/09/22 10:48:41 OK 20241026095416_initial_model.sql (9.11ms)10982026/09/22 10:48:41 OK 20251210153512_drop_unused_gin_index.sql (788.71µs)10992026/09/22 10:48:41 OK 20251218171726_add_pins.sql (2.18ms)11002026/09/22 10:48:41 OK 20251218171726_add_pins.sql (8.36ms)11012026-09-22 10:48:41.390 UTC [52728] ERROR: relation "goose_db_version" does not exist at character 3611022026-09-22 10:48:41.390 UTC [52728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11032026/09/22 10:48:41 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)11042026/09/22 10:48:41 OK 20241026095416_initial_model.sql (16.95ms)11052026/09/22 10:48:41 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)11062026/09/22 10:48:41 OK 20260905000000_add_claims.sql (3.03ms)11072026/09/22 10:48:41 OK 20260920000000_drop_claims.sql (1.61ms)11082026/09/22 10:48:41 goose: successfully migrated database to version: 2026092000000011092026/09/22 10:48:41 OK 20260628120000_add_object_size_and_stats.sql (7.83ms)11102026/09/22 10:48:41 OK 20251218171726_add_pins.sql (2.79ms)11112026/09/22 10:48:41 OK 1_commit_pending_closure.sql (1.25ms)11122026/09/22 10:48:41 OK 2_object_stats_trigger.sql (600.08µs)11132026/09/22 10:48:41 goose: up to current file version: 211142026/09/22 10:48:41 OK 20260905000000_add_claims.sql (4.11ms)11152026/09/22 10:48:41 OK 20260920000000_drop_claims.sql (6.37ms)11162026/09/22 10:48:41 goose: successfully migrated database to version: 2026092000000011172026/09/22 10:48:41 OK 1_commit_pending_closure.sql (1.9ms)11182026/09/22 10:48:41 OK 2_object_stats_trigger.sql (594.46µs)11192026/09/22 10:48:41 goose: up to current file version: 211202026/09/22 10:48:41 OK 20260628120000_add_object_size_and_stats.sql (21.29ms)11212026/09/22 10:48:41 OK 20260905000000_add_claims.sql (18.76ms)11222026/09/22 10:48:41 OK 20241026095416_initial_model.sql (52.96ms)11232026/09/22 10:48:41 OK 20260920000000_drop_claims.sql (14.02ms)11242026/09/22 10:48:41 goose: successfully migrated database to version: 2026092000000011252026/09/22 10:48:41 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)11262026/09/22 10:48:41 OK 1_commit_pending_closure.sql (1.61ms)11272026/09/22 10:48:41 OK 2_object_stats_trigger.sql (646.46µs)11282026/09/22 10:48:41 goose: up to current file version: 211292026/09/22 10:48:41 OK 20251218171726_add_pins.sql (3.58ms)11302026/09/22 10:48:41 OK 20260628120000_add_object_size_and_stats.sql (20.62ms)11312026/09/22 10:48:41 OK 20260905000000_add_claims.sql (14.99ms)11322026-09-22 10:48:41.499 UTC [52747] ERROR: relation "goose_db_version" does not exist at character 3611332026-09-22 10:48:41.499 UTC [52747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/09/22 10:48:41 OK 20260920000000_drop_claims.sql (12.52ms)11352026/09/22 10:48:41 goose: successfully migrated database to version: 2026092000000011362026/09/22 10:48:41 OK 1_commit_pending_closure.sql (2.02ms)11372026/09/22 10:48:41 OK 2_object_stats_trigger.sql (625.17µs)11382026/09/22 10:48:41 goose: up to current file version: 21139--- PASS: TestService_ReadAuthMiddleware (0.79s)1140=== CONT TestLeadElectsOneAndHandsOver11412026/09/22 10:48:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3003 objects_failed=01142=== NAME TestClientIntegration1143 client_integration_test.go:323: Objects in database after GC:1144 client_integration_test.go:323: Successfully deleted all objects with GC --force11452026/09/22 10:48:41 OK 20241026095416_initial_model.sql (63.08ms)11462026/09/22 10:48:41 OK 20251210153512_drop_unused_gin_index.sql (8.01ms)1147--- PASS: TestClientIntegration (2.86s)1148=== CONT TestResolveDBConnectionString1149=== RUN TestResolveDBConnectionString/flag_wins1150=== PAUSE TestResolveDBConnectionString/flag_wins1151=== RUN TestResolveDBConnectionString/file_when_flag_empty1152=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1153=== RUN TestResolveDBConnectionString/missing_file_is_an_error1154=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1155=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1156=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1157=== RUN TestResolveDBConnectionString/nothing_configured1158=== PAUSE TestResolveDBConnectionString/nothing_configured1159=== CONT TestCompletedNarNotReofferedAcrossClosures11602026/09/22 10:48:41 OK 20251218171726_add_pins.sql (3.36ms)11612026/09/22 10:48:41 OK 20260628120000_add_object_size_and_stats.sql (24.99ms)11622026-09-22 10:48:41.642 UTC [52774] ERROR: relation "goose_db_version" does not exist at character 3611632026-09-22 10:48:41.642 UTC [52774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11642026/09/22 10:48:41 OK 20260905000000_add_claims.sql (27.81ms)11652026/09/22 10:48:41 OK 20260920000000_drop_claims.sql (27.83ms)11662026/09/22 10:48:41 goose: successfully migrated database to version: 2026092000000011672026/09/22 10:48:41 OK 1_commit_pending_closure.sql (2.28ms)11682026/09/22 10:48:41 OK 2_object_stats_trigger.sql (707µs)11692026/09/22 10:48:41 goose: up to current file version: 21170=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1171=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1172=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1173=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1174=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1175=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1176=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1177=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1178=== CONT TestSkippedUploadsHandler11792026/09/22 10:48:41 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001180--- PASS: TestSkippedUploadsHandler (0.00s)1181=== CONT TestParseSize1182--- PASS: TestParseSize (0.00s)1183=== CONT TestService_Rustfstest11842026/09/22 10:48:41 OK 20241026095416_initial_model.sql (71.84ms)11852026/09/22 10:48:41 OK 20251210153512_drop_unused_gin_index.sql (5.62ms)11862026/09/22 10:48:41 OK 20251218171726_add_pins.sql (4.31ms)11872026/09/22 10:48:41 OK 20260628120000_add_object_size_and_stats.sql (18.52ms)11882026/09/22 10:48:41 OK 20260905000000_add_claims.sql (13.82ms)11892026/09/22 10:48:41 OK 20260920000000_drop_claims.sql (18.53ms)11902026/09/22 10:48:41 goose: successfully migrated database to version: 2026092000000011912026/09/22 10:48:41 OK 1_commit_pending_closure.sql (1.77ms)11922026/09/22 10:48:41 OK 2_object_stats_trigger.sql (570.67µs)11932026/09/22 10:48:41 goose: up to current file version: 211942026/09/22 10:48:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"11952026/09/22 10:48:41 WARN mTLS auth: bound subjects configured but subject DN unavailable11962026/09/22 10:48:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1197--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.08s)1198=== CONT TestPresignedUploadRegisteredBeforeCommit1199--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.11s)1200=== CONT TestCompleteMultipartUnregistered12012026/09/22 10:48:42 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01202=== NAME TestPinProtectsFromGC1203 client_integration_test.go:794: Pin successfully protected closure from garbage collection1204--- PASS: TestPinProtectsFromGC (3.36s)1205=== CONT TestReadProxyDisabled12062026-09-22 10:48:42.148 UTC [52842] ERROR: relation "goose_db_version" does not exist at character 3612072026-09-22 10:48:42.148 UTC [52842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12082026/09/22 10:48:42 INFO Aborted multipart uploads count=012092026/09/22 10:48:42 WARN Force mode enabled - objects will be deleted immediately without grace period12102026/09/22 10:48:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012112026/09/22 10:48:42 INFO Vacuumed table table=pending_closures12122026/09/22 10:48:42 INFO Vacuumed table table=pending_objects12132026/09/22 10:48:42 INFO Vacuumed table table=multipart_uploads12142026/09/22 10:48:42 INFO Vacuumed table table=closures12152026/09/22 10:48:42 INFO Vacuumed table table=objects1216--- PASS: TestGCMetrics (1.26s)1217=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT12182026/09/22 10:48:42 OK 20241026095416_initial_model.sql (101.65ms)12192026/09/22 10:48:42 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)12202026/09/22 10:48:42 OK 20251218171726_add_pins.sql (24.34ms)12212026/09/22 10:48:42 OK 20260628120000_add_object_size_and_stats.sql (22.99ms)12222026/09/22 10:48:42 OK 20260905000000_add_claims.sql (12.85ms)12232026/09/22 10:48:42 OK 20260920000000_drop_claims.sql (1.44ms)12242026/09/22 10:48:42 goose: successfully migrated database to version: 2026092000000012252026/09/22 10:48:42 OK 1_commit_pending_closure.sql (1.74ms)12262026/09/22 10:48:42 OK 2_object_stats_trigger.sql (732.96µs)12272026/09/22 10:48:42 goose: up to current file version: 212282026-09-22 10:48:42.358 UTC [52853] ERROR: relation "goose_db_version" does not exist at character 3612292026-09-22 10:48:42.358 UTC [52853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12302026/09/22 10:48:42 OK 20241026095416_initial_model.sql (56.47ms)12312026-09-22 10:48:42.482 UTC [52868] ERROR: relation "goose_db_version" does not exist at character 3612322026-09-22 10:48:42.482 UTC [52868] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12332026/09/22 10:48:42 OK 20251210153512_drop_unused_gin_index.sql (32.61ms)12342026-09-22 10:48:42.519 UTC [52880] ERROR: relation "goose_db_version" does not exist at character 3612352026-09-22 10:48:42.519 UTC [52880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026/09/22 10:48:42 OK 20251218171726_add_pins.sql (37.59ms)12372026/09/22 10:48:42 OK 20260628120000_add_object_size_and_stats.sql (37.58ms)1238--- PASS: TestGCBugBareHashReferences (1.50s)1239=== CONT TestReadProxyRootRedirectsToIndexHTML12402026/09/22 10:48:42 OK 20260905000000_add_claims.sql (25.11ms)12412026/09/22 10:48:42 INFO lead: acquired remote=192.0.2.1:123412422026/09/22 10:48:42 INFO lead: released remote=192.0.2.1:12341243--- PASS: TestLeadEndsOnShutdown (1.26s)1244=== CONT TestReadProxyConditionalGet12452026/09/22 10:48:42 OK 20260920000000_drop_claims.sql (20.48ms)12462026/09/22 10:48:42 goose: successfully migrated database to version: 2026092000000012472026/09/22 10:48:42 OK 20241026095416_initial_model.sql (75.92ms)12482026/09/22 10:48:42 OK 1_commit_pending_closure.sql (1.9ms)12492026/09/22 10:48:42 OK 2_object_stats_trigger.sql (659.42µs)12502026/09/22 10:48:42 goose: up to current file version: 212512026/09/22 10:48:42 OK 20251210153512_drop_unused_gin_index.sql (7.89ms)12522026/09/22 10:48:42 OK 20241026095416_initial_model.sql (81.86ms)12532026/09/22 10:48:42 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)12542026/09/22 10:48:42 OK 20251218171726_add_pins.sql (18.63ms)12552026/09/22 10:48:42 OK 20251218171726_add_pins.sql (14.58ms)12562026/09/22 10:48:42 OK 20260628120000_add_object_size_and_stats.sql (25.24ms)12572026/09/22 10:48:42 OK 20260628120000_add_object_size_and_stats.sql (27.08ms)12582026/09/22 10:48:42 OK 20260905000000_add_claims.sql (22.91ms)12592026/09/22 10:48:42 OK 20260905000000_add_claims.sql (7.34ms)12602026/09/22 10:48:42 OK 20260920000000_drop_claims.sql (7.94ms)12612026/09/22 10:48:42 goose: successfully migrated database to version: 2026092000000012622026/09/22 10:48:42 OK 20260920000000_drop_claims.sql (9.51ms)12632026/09/22 10:48:42 goose: successfully migrated database to version: 2026092000000012642026/09/22 10:48:42 OK 1_commit_pending_closure.sql (1.78ms)12652026/09/22 10:48:42 OK 2_object_stats_trigger.sql (638.54µs)12662026/09/22 10:48:42 goose: up to current file version: 212672026/09/22 10:48:42 OK 1_commit_pending_closure.sql (1.9ms)12682026/09/22 10:48:42 OK 2_object_stats_trigger.sql (561.04µs)12692026/09/22 10:48:42 goose: up to current file version: 212702026-09-22 10:48:42.714 UTC [52933] ERROR: relation "goose_db_version" does not exist at character 3612712026-09-22 10:48:42.714 UTC [52933] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12722026/09/22 10:48:42 INFO lead: acquired remote=192.0.2.1:123412732026/09/22 10:48:42 OK 20241026095416_initial_model.sql (90.26ms)12742026-09-22 10:48:42.841 UTC [52969] ERROR: relation "goose_db_version" does not exist at character 3612752026-09-22 10:48:42.841 UTC [52969] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12762026/09/22 10:48:42 OK 20251210153512_drop_unused_gin_index.sql (10.31ms)12772026-09-22 10:48:42.851 UTC [52970] ERROR: relation "goose_db_version" does not exist at character 3612782026-09-22 10:48:42.851 UTC [52970] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026/09/22 10:48:42 OK 20251218171726_add_pins.sql (32.84ms)12802026/09/22 10:48:42 OK 20260628120000_add_object_size_and_stats.sql (20.04ms)12812026-09-22 10:48:42.910 UTC [52977] ERROR: relation "goose_db_version" does not exist at character 3612822026-09-22 10:48:42.910 UTC [52977] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12832026/09/22 10:48:42 INFO lead: released remote=192.0.2.1:123412842026/09/22 10:48:42 OK 20260905000000_add_claims.sql (15.4ms)12852026/09/22 10:48:42 OK 20260920000000_drop_claims.sql (8.99ms)12862026/09/22 10:48:42 goose: successfully migrated database to version: 2026092000000012872026/09/22 10:48:42 OK 1_commit_pending_closure.sql (2.28ms)12882026/09/22 10:48:42 OK 2_object_stats_trigger.sql (824.42µs)12892026/09/22 10:48:42 goose: up to current file version: 212902026/09/22 10:48:42 OK 20241026095416_initial_model.sql (58.52ms)12912026/09/22 10:48:42 OK 20251210153512_drop_unused_gin_index.sql (6.03ms)12922026/09/22 10:48:42 INFO lead: acquired remote=192.0.2.1:123412932026/09/22 10:48:42 INFO lead: released remote=192.0.2.1:12341294--- PASS: TestLeadElectsOneAndHandsOver (1.42s)1295=== CONT TestReadProxyHead12962026/09/22 10:48:42 OK 20241026095416_initial_model.sql (59.17ms)12972026/09/22 10:48:42 OK 20251210153512_drop_unused_gin_index.sql (7.09ms)12982026/09/22 10:48:42 OK 20251218171726_add_pins.sql (19.41ms)12992026/09/22 10:48:42 OK 20251218171726_add_pins.sql (8.24ms)1300--- PASS: TestService_Rustfstest (1.28s)1301=== CONT TestReadProxyInvalidPath13022026/09/22 10:48:42 OK 20260628120000_add_object_size_and_stats.sql (9.15ms)13032026/09/22 10:48:43 OK 20241026095416_initial_model.sql (77.52ms)13042026/09/22 10:48:43 OK 20260628120000_add_object_size_and_stats.sql (36.97ms)13052026/09/22 10:48:43 OK 20251210153512_drop_unused_gin_index.sql (11.78ms)13062026/09/22 10:48:43 OK 20260905000000_add_claims.sql (47.34ms)13072026/09/22 10:48:43 OK 20251218171726_add_pins.sql (7.08ms)13082026/09/22 10:48:43 OK 20260905000000_add_claims.sql (12.99ms)13092026/09/22 10:48:43 OK 20260920000000_drop_claims.sql (7.05ms)13102026/09/22 10:48:43 goose: successfully migrated database to version: 2026092000000013112026/09/22 10:48:43 OK 20260920000000_drop_claims.sql (7.69ms)13122026/09/22 10:48:43 goose: successfully migrated database to version: 2026092000000013132026/09/22 10:48:43 OK 20260628120000_add_object_size_and_stats.sql (36.13ms)13142026/09/22 10:48:43 OK 1_commit_pending_closure.sql (28.58ms)13152026/09/22 10:48:43 OK 1_commit_pending_closure.sql (28.53ms)13162026/09/22 10:48:43 OK 2_object_stats_trigger.sql (527.21µs)13172026/09/22 10:48:43 goose: up to current file version: 213182026/09/22 10:48:43 OK 2_object_stats_trigger.sql (696.13µs)13192026/09/22 10:48:43 goose: up to current file version: 213202026/09/22 10:48:43 OK 20260905000000_add_claims.sql (24.11ms)13212026/09/22 10:48:43 OK 20260920000000_drop_claims.sql (18.31ms)13222026/09/22 10:48:43 goose: successfully migrated database to version: 2026092000000013232026/09/22 10:48:43 OK 1_commit_pending_closure.sql (2.08ms)13242026/09/22 10:48:43 OK 2_object_stats_trigger.sql (633.75µs)13252026/09/22 10:48:43 goose: up to current file version: 213262026/09/22 10:48:43 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/22 10:48:43 INFO Received uploads request method=POST path=/api/pending_closures13282026/09/22 10:48:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13292026/09/22 10:48:43 INFO Received uploads request method=POST path=/api/pending_closures1330--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.46s)1331=== CONT TestReadProxy40413322026-09-22 10:48:43.488 UTC [53123] ERROR: relation "goose_db_version" does not exist at character 3613332026-09-22 10:48:43.488 UTC [53123] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13342026-09-22 10:48:43.494 UTC [53124] ERROR: relation "goose_db_version" does not exist at character 3613352026-09-22 10:48:43.494 UTC [53124] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1336--- PASS: TestReadProxyDisabled (1.41s)1337=== CONT TestReadProxyNarStreaming13382026/09/22 10:48:43 WARN Rate limiter enabled after throttle name=s3-test rate=513392026/09/22 10:48:43 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1340=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1341 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101342 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001343--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.89s)1344=== CONT TestReadProxyNarinfoAlreadyDecompressed13452026/09/22 10:48:43 OK 20241026095416_initial_model.sql (93.1ms)13462026/09/22 10:48:43 OK 20251210153512_drop_unused_gin_index.sql (6.58ms)13472026/09/22 10:48:43 OK 20251218171726_add_pins.sql (19.88ms)13482026/09/22 10:48:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13492026/09/22 10:48:43 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1350--- PASS: TestCompleteMultipartUnregistered (1.69s)1351=== CONT TestReadProxyNarinfo13522026/09/22 10:48:43 OK 20241026095416_initial_model.sql (122.02ms)13532026/09/22 10:48:43 OK 20251210153512_drop_unused_gin_index.sql (11.78ms)13542026/09/22 10:48:43 OK 20260628120000_add_object_size_and_stats.sql (42.74ms)13552026/09/22 10:48:43 OK 20251218171726_add_pins.sql (35.46ms)13562026/09/22 10:48:43 OK 20260905000000_add_claims.sql (35.76ms)13572026/09/22 10:48:43 OK 20260628120000_add_object_size_and_stats.sql (20.05ms)13582026/09/22 10:48:43 OK 20260920000000_drop_claims.sql (5.06ms)13592026/09/22 10:48:43 goose: successfully migrated database to version: 2026092000000013602026/09/22 10:48:43 OK 1_commit_pending_closure.sql (2.1ms)13612026/09/22 10:48:43 OK 2_object_stats_trigger.sql (665.38µs)13622026/09/22 10:48:43 goose: up to current file version: 213632026/09/22 10:48:43 OK 20260905000000_add_claims.sql (81.59ms)13642026/09/22 10:48:43 OK 20260920000000_drop_claims.sql (31.34ms)13652026/09/22 10:48:43 goose: successfully migrated database to version: 2026092000000013662026/09/22 10:48:43 OK 1_commit_pending_closure.sql (1.95ms)13672026/09/22 10:48:43 OK 2_object_stats_trigger.sql (798µs)13682026/09/22 10:48:43 goose: up to current file version: 213692026/09/22 10:48:43 INFO Received uploads request method=POST path=/api/pending_closures1370--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.84s)1371=== CONT TestIsValidCachePath1372=== RUN TestIsValidCachePath/narinfo1373=== PAUSE TestIsValidCachePath/narinfo1374=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1375=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1376=== RUN TestIsValidCachePath/nar_zst1377=== PAUSE TestIsValidCachePath/nar_zst1378=== RUN TestIsValidCachePath/nar_xz1379=== PAUSE TestIsValidCachePath/nar_xz1380=== RUN TestIsValidCachePath/nar_bz21381=== PAUSE TestIsValidCachePath/nar_bz21382=== RUN TestIsValidCachePath/nar_uncompressed1383=== PAUSE TestIsValidCachePath/nar_uncompressed1384=== RUN TestIsValidCachePath/ls1385=== PAUSE TestIsValidCachePath/ls1386=== RUN TestIsValidCachePath/log1387=== PAUSE TestIsValidCachePath/log1388=== RUN TestIsValidCachePath/realisation1389=== PAUSE TestIsValidCachePath/realisation1390=== RUN TestIsValidCachePath/nix-cache-info1391=== PAUSE TestIsValidCachePath/nix-cache-info1392=== RUN TestIsValidCachePath/index.html1393=== PAUSE TestIsValidCachePath/index.html1394==2026-09-22 10:48:44.015 UTC [53216] ERROR: relation "goose_db_version" does not exist at character 3613952026-09-22 10:48:44.015 UTC [53216] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1396= RUN TestIsValidCachePath/traversal_parent1397=== PAUSE TestIsValidCachePath/traversal_parent1398=== RUN TestIsValidCachePath/traversal_in_middle1399=== PAUSE TestIsValidCachePath/traversal_in_middle1400=== RUN TestIsValidCachePath/invalid_char_e1401=== PAUSE TestIsValidCachePath/invalid_char_e1402=== RUN TestIsValidCachePath/invalid_char_u1403=== PAUSE TestIsValidCachePath/invalid_char_u1404=== RUN TestIsValidCachePath/random_path1405=== PAUSE TestIsValidCachePath/random_path1406=== RUN TestIsValidCachePath/empty1407=== PAUSE TestIsValidCachePath/empty1408=== RUN TestIsValidCachePath/leading_slash1409=== PAUSE TestIsValidCachePath/leading_slash1410=== RUN TestIsValidCachePath/wrong_extension1411=== PAUSE TestIsValidCachePath/wrong_extension1412=== RUN TestIsValidCachePath/short_hash1413=== PAUSE TestIsValidCachePath/short_hash1414=== CONT TestParseSingleRange1415=== RUN TestParseSingleRange/none1416=== PAUSE TestParseSingleRange/none1417=== RUN TestParseSingleRange/unknown_unit1418=== PAUSE TestParseSingleRange/unknown_unit1419=== RUN TestParseSingleRange/multi-range_ignored1420=== PAUSE TestParseSingleRange/multi-range_ignored1421=== RUN TestParseSingleRange/malformed_no_dash1422=== PAUSE TestParseSingleRange/malformed_no_dash1423=== RUN TestParseSingleRange/malformed_both_empty1424=== PAUSE TestParseSingleRange/malformed_both_empty1425=== RUN TestParseSingleRange/malformed_end_before_start1426=== PAUSE TestParseSingleRange/malformed_end_before_start1427=== RUN TestParseSingleRange/closed1428=== PAUSE TestParseSingleRange/closed1429=== RUN TestParseSingleRange/open-ended1430=== PAUSE TestParseSingleRange/open-ended1431=== RUN TestParseSingleRange/end_clamped_to_size1432=== PAUSE TestParseSingleRange/end_clamped_to_size1433=== RUN TestParseSingleRange/suffix1434=== PAUSE TestParseSingleRange/suffix1435=== RUN TestParseSingleRange/suffix_exceeds_size1436=== PAUSE TestParseSingleRange/suffix_exceeds_size1437=== RUN TestParseSingleRange/single_byte1438=== PAUSE TestParseSingleRange/single_byte1439=== RUN TestParseSingleRange/start_past_EOF1440=== PAUSE TestParseSingleRange/start_past_EOF1441=== RUN TestParseSingleRange/start_far_past_EOF1442=== PAUSE TestParseSingleRange/start_far_past_EOF1443=== CONT TestCreatePin_ReservedPins14442026-09-22 10:48:44.036 UTC [53226] ERROR: relation "goose_db_version" does not exist at character 3614452026-09-22 10:48:44.036 UTC [53226] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14462026/09/22 10:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58536/oidc14472026/09/22 10:48:44 OK 20241026095416_initial_model.sql (102.84ms)14482026/09/22 10:48:44 OK 20251210153512_drop_unused_gin_index.sql (12.43ms)14492026/09/22 10:48:44 OK 20251218171726_add_pins.sql (28.07ms)1450--- PASS: TestReadProxyConditionalGet (1.60s)1451=== CONT TestResurrectedObjectNotDeleted14522026/09/22 10:48:44 OK 20260628120000_add_object_size_and_stats.sql (13.25ms)14532026/09/22 10:48:44 OK 20241026095416_initial_model.sql (121.33ms)14542026/09/22 10:48:44 OK 20251210153512_drop_unused_gin_index.sql (17.58ms)14552026/09/22 10:48:44 OK 20260905000000_add_claims.sql (27.57ms)14562026/09/22 10:48:44 OK 20260920000000_drop_claims.sql (15.89ms)14572026/09/22 10:48:44 goose: successfully migrated database to version: 2026092000000014582026/09/22 10:48:44 OK 20251218171726_add_pins.sql (27.29ms)14592026/09/22 10:48:44 OK 1_commit_pending_closure.sql (4.81ms)14602026/09/22 10:48:44 OK 2_object_stats_trigger.sql (1.34ms)14612026/09/22 10:48:44 goose: up to current file version: 214622026/09/22 10:48:44 OK 20260628120000_add_object_size_and_stats.sql (37.41ms)14632026/09/22 10:48:44 OK 20260905000000_add_claims.sql (44.49ms)14642026/09/22 10:48:44 OK 20260920000000_drop_claims.sql (30.99ms)14652026/09/22 10:48:44 goose: successfully migrated database to version: 2026092000000014662026/09/22 10:48:44 OK 1_commit_pending_closure.sql (2.61ms)14672026/09/22 10:48:44 OK 2_object_stats_trigger.sql (837.5µs)14682026/09/22 10:48:44 goose: up to current file version: 214692026-09-22 10:48:44.384 UTC [53292] ERROR: relation "goose_db_version" does not exist at character 3614702026-09-22 10:48:44.384 UTC [53292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1471--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.88s)1472=== CONT TestOrphanedObjectsGCStressTest14732026/09/22 10:48:44 OK 20241026095416_initial_model.sql (185.98ms)14742026/09/22 10:48:44 OK 20251210153512_drop_unused_gin_index.sql (14.55ms)14752026/09/22 10:48:44 OK 20251218171726_add_pins.sql (29.24ms)14762026/09/22 10:48:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14772026/09/22 10:48:44 OK 20260628120000_add_object_size_and_stats.sql (54.73ms)1478--- PASS: TestReadProxyHead (1.78s)1479=== CONT TestOrphanedObjectsGC14802026/09/22 10:48:44 OK 20260905000000_add_claims.sql (69.64ms)14812026/09/22 10:48:44 OK 20260920000000_drop_claims.sql (32.18ms)14822026/09/22 10:48:44 goose: successfully migrated database to version: 2026092000000014832026/09/22 10:48:44 OK 1_commit_pending_closure.sql (4.05ms)14842026/09/22 10:48:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjA3M2E2M2YtNWUyYy00ODg1LWFhZGItNDBiMGQzNjQ3NGY3LjYxMmQ0N2I5LWU2OWUtNDBmZS1iNGM2LTQ3Y2M4NTA5NzliMHgxNzkwMDc0MTIzMTU3Njk4MDAw parts=1214852026/09/22 10:48:44 OK 2_object_stats_trigger.sql (526.71µs)14862026/09/22 10:48:44 goose: up to current file version: 214872026/09/22 10:48:44 INFO Received uploads request method=POST path=/api/pending_closures1488--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.21s)1489=== CONT TestObjectStatsTrigger14902026-09-22 10:48:44.817 UTC [53351] ERROR: relation "goose_db_version" does not exist at character 3614912026-09-22 10:48:44.817 UTC [53351] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14922026-09-22 10:48:44.830 UTC [53353] ERROR: relation "goose_db_version" does not exist at character 3614932026-09-22 10:48:44.830 UTC [53353] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14942026-09-22 10:48:44.870 UTC [53356] ERROR: relation "goose_db_version" does not exist at character 3614952026-09-22 10:48:44.870 UTC [53356] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14962026/09/22 10:48:44 OK 20241026095416_initial_model.sql (60.99ms)14972026/09/22 10:48:44 OK 20251210153512_drop_unused_gin_index.sql (7.9ms)14982026/09/22 10:48:44 OK 20251218171726_add_pins.sql (29.82ms)14992026/09/22 10:48:44 OK 20241026095416_initial_model.sql (112.99ms)1500--- PASS: TestReadProxyInvalidPath (2.01s)1501=== CONT TestMultipartCleanup15022026/09/22 10:48:44 OK 20251210153512_drop_unused_gin_index.sql (5.61ms)15032026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (33.6ms)15042026/09/22 10:48:45 OK 20251218171726_add_pins.sql (32.43ms)15052026/09/22 10:48:45 OK 20241026095416_initial_model.sql (145.95ms)15062026/09/22 10:48:45 OK 20260905000000_add_claims.sql (48.8ms)15072026-09-22 10:48:45.075 UTC [53401] ERROR: relation "goose_db_version" does not exist at character 3615082026-09-22 10:48:45.075 UTC [53401] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15092026/09/22 10:48:45 OK 20260920000000_drop_claims.sql (19.54ms)15102026/09/22 10:48:45 goose: successfully migrated database to version: 2026092000000015112026/09/22 10:48:45 OK 20251210153512_drop_unused_gin_index.sql (20.44ms)15122026/09/22 10:48:45 OK 1_commit_pending_closure.sql (3.1ms)15132026/09/22 10:48:45 OK 2_object_stats_trigger.sql (735.13µs)15142026/09/22 10:48:45 goose: up to current file version: 215152026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (61.12ms)15162026/09/22 10:48:45 OK 20251218171726_add_pins.sql (24.34ms)15172026/09/22 10:48:45 OK 20260905000000_add_claims.sql (23.47ms)15182026/09/22 10:48:45 OK 20260920000000_drop_claims.sql (15ms)15192026/09/22 10:48:45 goose: successfully migrated database to version: 2026092000000015202026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (23.24ms)15212026/09/22 10:48:45 OK 20260905000000_add_claims.sql (8.27ms)15222026/09/22 10:48:45 OK 1_commit_pending_closure.sql (8.86ms)15232026/09/22 10:48:45 OK 2_object_stats_trigger.sql (1.4ms)15242026/09/22 10:48:45 goose: up to current file version: 215252026/09/22 10:48:45 OK 20260920000000_drop_claims.sql (27.98ms)15262026/09/22 10:48:45 goose: successfully migrated database to version: 2026092000000015272026/09/22 10:48:45 OK 1_commit_pending_closure.sql (2.24ms)15282026/09/22 10:48:45 OK 2_object_stats_trigger.sql (619.21µs)15292026/09/22 10:48:45 goose: up to current file version: 21530--- PASS: TestReadProxy404 (1.93s)1531=== CONT TestServerTLSConfig1532=== RUN TestServerTLSConfig/no_client_CA1533=== PAUSE TestServerTLSConfig/no_client_CA1534=== RUN TestServerTLSConfig/missing_CA_file1535=== PAUSE TestServerTLSConfig/missing_CA_file1536=== RUN TestServerTLSConfig/not_a_PEM_file1537=== PAUSE TestServerTLSConfig/not_a_PEM_file1538=== CONT TestService_NativeMTLS15392026/09/22 10:48:45 OK 20241026095416_initial_model.sql (138.03ms)15402026/09/22 10:48:45 OK 20251210153512_drop_unused_gin_index.sql (14.11ms)15412026/09/22 10:48:45 OK 20251218171726_add_pins.sql (31.82ms)15422026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (31.89ms)15432026-09-22 10:48:45.367 UTC [53450] ERROR: relation "goose_db_version" does not exist at character 3615442026-09-22 10:48:45.367 UTC [53450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15452026/09/22 10:48:45 OK 20260905000000_add_claims.sql (21.57ms)15462026/09/22 10:48:45 OK 20260920000000_drop_claims.sql (8.71ms)15472026/09/22 10:48:45 goose: successfully migrated database to version: 2026092000000015482026/09/22 10:48:45 OK 1_commit_pending_closure.sql (6.3ms)15492026/09/22 10:48:45 OK 2_object_stats_trigger.sql (3.25ms)15502026/09/22 10:48:45 goose: up to current file version: 215512026/09/22 10:48:45 OK 20241026095416_initial_model.sql (87.3ms)1552--- PASS: TestReadProxyNarStreaming (1.99s)1553=== CONT TestMetricsInventory15542026/09/22 10:48:45 OK 20251210153512_drop_unused_gin_index.sql (6.99ms)15552026/09/22 10:48:45 OK 20251218171726_add_pins.sql (36.24ms)15562026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (38.19ms)15572026-09-22 10:48:45.599 UTC [53501] ERROR: relation "goose_db_version" does not exist at character 3615582026-09-22 10:48:45.599 UTC [53501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15592026/09/22 10:48:45 OK 20260905000000_add_claims.sql (33.63ms)15602026/09/22 10:48:45 OK 20260920000000_drop_claims.sql (20.14ms)15612026/09/22 10:48:45 goose: successfully migrated database to version: 2026092000000015622026/09/22 10:48:45 OK 1_commit_pending_closure.sql (3.14ms)15632026/09/22 10:48:45 OK 2_object_stats_trigger.sql (648.63µs)15642026/09/22 10:48:45 goose: up to current file version: 215652026-09-22 10:48:45.673 UTC [53516] ERROR: relation "goose_db_version" does not exist at character 3615662026-09-22 10:48:45.673 UTC [53516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15672026-09-22 10:48:45.673 UTC [53511] ERROR: relation "goose_db_version" does not exist at character 3615682026-09-22 10:48:45.673 UTC [53511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1569--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.11s)1570=== CONT TestNARDeduplicationMetadataUploadBug15712026/09/22 10:48:45 OK 20241026095416_initial_model.sql (101.66ms)15722026/09/22 10:48:45 OK 20251210153512_drop_unused_gin_index.sql (11.6ms)15732026/09/22 10:48:45 OK 20251218171726_add_pins.sql (21.37ms)15742026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (47.68ms)15752026/09/22 10:48:45 OK 20241026095416_initial_model.sql (119.99ms)15762026/09/22 10:48:45 OK 20241026095416_initial_model.sql (141.85ms)15772026/09/22 10:48:45 OK 20251210153512_drop_unused_gin_index.sql (17.29ms)15782026/09/22 10:48:45 OK 20260905000000_add_claims.sql (40.81ms)15792026-09-22 10:48:45.882 UTC [53575] ERROR: relation "goose_db_version" does not exist at character 3615802026-09-22 10:48:45.882 UTC [53575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15812026/09/22 10:48:45 OK 20251210153512_drop_unused_gin_index.sql (56.85ms)15822026/09/22 10:48:45 OK 20251218171726_add_pins.sql (47.45ms)15832026/09/22 10:48:45 OK 20260920000000_drop_claims.sql (49.94ms)15842026/09/22 10:48:45 goose: successfully migrated database to version: 2026092000000015852026/09/22 10:48:45 OK 20251218171726_add_pins.sql (17.77ms)15862026/09/22 10:48:45 OK 1_commit_pending_closure.sql (2ms)15872026/09/22 10:48:45 OK 2_object_stats_trigger.sql (575.83µs)15882026/09/22 10:48:45 goose: up to current file version: 215892026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (29.66ms)15902026/09/22 10:48:45 OK 20260628120000_add_object_size_and_stats.sql (45.23ms)1591--- PASS: TestReadProxyNarinfo (2.28s)1592=== CONT TestCreatePendingClosureRejectsOversizedNAR15932026/09/22 10:48:45 INFO Received uploads request method=POST path=/api/pending_closures1594--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1595=== CONT TestCacheConfigHandlerMaxNarSize1596--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1597=== CONT TestGenerateLandingPage1598--- PASS: TestGenerateLandingPage (0.00s)1599=== CONT TestService_readinessHandler16002026/09/22 10:48:46 OK 20260905000000_add_claims.sql (64.04ms)16012026/09/22 10:48:46 OK 20260920000000_drop_claims.sql (38.89ms)16022026/09/22 10:48:46 goose: successfully migrated database to version: 2026092000000016032026/09/22 10:48:46 OK 1_commit_pending_closure.sql (2.1ms)16042026/09/22 10:48:46 OK 2_object_stats_trigger.sql (651.71µs)16052026/09/22 10:48:46 goose: up to current file version: 216062026/09/22 10:48:46 OK 20260905000000_add_claims.sql (74.61ms)16072026/09/22 10:48:46 OK 20260920000000_drop_claims.sql (28.57ms)16082026/09/22 10:48:46 goose: successfully migrated database to version: 2026092000000016092026/09/22 10:48:46 OK 1_commit_pending_closure.sql (2.11ms)16102026/09/22 10:48:46 OK 2_object_stats_trigger.sql (634.5µs)16112026/09/22 10:48:46 goose: up to current file version: 216122026/09/22 10:48:46 OK 20241026095416_initial_model.sql (179.51ms)16132026/09/22 10:48:46 OK 20251210153512_drop_unused_gin_index.sql (7.9ms)16142026/09/22 10:48:46 OK 20251218171726_add_pins.sql (17.03ms)16152026/09/22 10:48:46 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16162026/09/22 10:48:46 WARN Refused reserved pin name=worker-x86_64-linux16172026/09/22 10:48:46 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16182026/09/22 10:48:46 INFO Received create pin request method=POST path=/api/pins/my-app16192026/09/22 10:48:46 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16202026/09/22 10:48:46 OK 20260628120000_add_object_size_and_stats.sql (31.51ms)1621--- PASS: TestCreatePin_ReservedPins (2.14s)1622=== CONT TestService_healthCheckHandler16232026/09/22 10:48:46 OK 20260905000000_add_claims.sql (43.84ms)16242026/09/22 10:48:46 OK 20260920000000_drop_claims.sql (22.9ms)16252026/09/22 10:48:46 goose: successfully migrated database to version: 2026092000000016262026/09/22 10:48:46 OK 1_commit_pending_closure.sql (2.34ms)16272026/09/22 10:48:46 OK 2_object_stats_trigger.sql (595.25µs)16282026/09/22 10:48:46 goose: up to current file version: 216292026-09-22 10:48:46.263 UTC [53598] ERROR: relation "goose_db_version" does not exist at character 3616302026-09-22 10:48:46.263 UTC [53598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1631--- PASS: TestResurrectedObjectNotDeleted (2.26s)1632=== CONT TestUploadHandlersRejectInvalidKeys1633=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1634=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1635=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1636=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1637=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1638=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1639=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1640=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1641=== CONT TestUploadHandlersRejectOversizedBody16422026/09/22 10:48:46 OK 20241026095416_initial_model.sql (177.59ms)1643=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1644=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1645=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1646=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1647=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1648=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1649=== CONT TestGCTaskStore_GetEmpty1650--- PASS: TestGCTaskStore_GetEmpty (0.00s)1651=== CONT TestGCTaskStore_GetReturnsLatest1652--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1653=== CONT TestIsValidUploadKey1654=== RUN TestIsValidUploadKey/narinfo1655=== PAUSE TestIsValidUploadKey/narinfo1656=== RUN TestIsValidUploadKey/nar_zst1657=== PAUSE TestIsValidUploadKey/nar_zst1658=== RUN TestIsValidUploadKey/nar_xz1659=== PAUSE TestIsValidUploadKey/nar_xz1660=== RUN TestIsValidUploadKey/nar_plain1661=== PAUSE TestIsValidUploadKey/nar_plain1662=== RUN TestIsValidUploadKey/listing1663=== PAUSE TestIsValidUploadKey/listing1664=== RUN TestIsValidUploadKey/build_log1665=== PAUSE TestIsValidUploadKey/build_log1666=== RUN TestIsValidUploadKey/build_log_home-manager_file1667=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1668=== RUN TestIsValidUploadKey/build_log_plus_in_name1669=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1670=== RUN TestIsValidUploadKey/build_log_question_mark1671=== PAUSE TestIsValidUploadKey/build_log_question_mark1672=== RUN TestIsValidUploadKey/build_log_equals1673=== PAUSE TestIsValidUploadKey/build_log_equals1674=== RUN TestIsValidUploadKey/realisation1675=== PAUSE TestIsValidUploadKey/realisation1676=== RUN TestIsValidUploadKey/realisation_plus_in_output1677=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1678=== RUN TestIsValidUploadKey/nix-cache-info1679=== PAUSE TestIsValidUploadKey/nix-cache-info1680=== RUN TestIsValidUploadKey/index.html1681=== PAUSE TestIsValidUploadKey/index.html1682=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1683=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1684=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1685=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1686=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1687=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1688=== RUN TestIsValidUploadKey/traversal1689=== PAUSE TestIsValidUploadKey/traversal1690=== RUN TestIsValidUploadKey/traversal_nar1691=== PAUSE TestIsValidUploadKey/traversal_nar1692=== RUN TestIsValidUploadKey/absolute1693=== PAUSE TestIsValidUploadKey/absolute1694=== RUN TestIsValidUploadKey/empty_key1695=== PAUSE TestIsValidUploadKey/empty_key1696=== RUN TestIsValidUploadKey/unknown_type1697=== PAUSE TestIsValidUploadKey/unknown_type1698=== CONT TestProxyWriteTimeout1699=== RUN TestProxyWriteTimeout/narinfo1700=== PAUSE TestProxyWriteTimeout/narinfo1701=== RUN TestProxyWriteTimeout/1_GiB_nar1702=== PAUSE TestProxyWriteTimeout/1_GiB_nar1703=== RUN TestProxyWriteTimeout/10_GiB_nar1704=== PAUSE TestProxyWriteTimeout/10_GiB_nar1705=== RUN TestProxyWriteTimeout/unknown_size1706=== PAUSE TestProxyWriteTimeout/unknown_size1707=== CONT TestService_verifyS3Integrity17082026/09/22 10:48:46 OK 20251210153512_drop_unused_gin_index.sql (10.68ms)17092026/09/22 10:48:46 OK 20251218171726_add_pins.sql (29.46ms)17102026/09/22 10:48:46 OK 20260628120000_add_object_size_and_stats.sql (23.36ms)17112026/09/22 10:48:46 OK 20260905000000_add_claims.sql (21.84ms)17122026/09/22 10:48:46 OK 20260920000000_drop_claims.sql (25.53ms)17132026/09/22 10:48:46 goose: successfully migrated database to version: 2026092000000017142026/09/22 10:48:46 OK 1_commit_pending_closure.sql (2.2ms)17152026/09/22 10:48:46 OK 2_object_stats_trigger.sql (616.92µs)17162026/09/22 10:48:46 goose: up to current file version: 217172026-09-22 10:48:46.602 UTC [53615] ERROR: relation "goose_db_version" does not exist at character 3617182026-09-22 10:48:46.602 UTC [53615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17192026/09/22 10:48:46 OK 20241026095416_initial_model.sql (107.48ms)17202026/09/22 10:48:46 OK 20251210153512_drop_unused_gin_index.sql (19.03ms)17212026/09/22 10:48:46 OK 20251218171726_add_pins.sql (26.11ms)17222026/09/22 10:48:46 OK 20260628120000_add_object_size_and_stats.sql (67.89ms)17232026/09/22 10:48:46 OK 20260905000000_add_claims.sql (34.76ms)17242026/09/22 10:48:46 OK 20260920000000_drop_claims.sql (11.43ms)17252026/09/22 10:48:46 goose: successfully migrated database to version: 2026092000000017262026/09/22 10:48:46 OK 1_commit_pending_closure.sql (2.45ms)17272026/09/22 10:48:46 OK 2_object_stats_trigger.sql (613.92µs)17282026/09/22 10:48:46 goose: up to current file version: 217292026-09-22 10:48:46.941 UTC [53630] ERROR: relation "goose_db_version" does not exist at character 3617302026-09-22 10:48:46.941 UTC [53630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17312026/09/22 10:48:47 OK 20241026095416_initial_model.sql (105.67ms)17322026/09/22 10:48:47 OK 20251210153512_drop_unused_gin_index.sql (13.4ms)1733--- PASS: TestObjectStatsTrigger (2.31s)1734=== CONT TestService_createPendingClosureHandler17352026/09/22 10:48:47 OK 20251218171726_add_pins.sql (25.96ms)17362026/09/22 10:48:47 OK 20260628120000_add_object_size_and_stats.sql (43.41ms)17372026/09/22 10:48:47 OK 20260905000000_add_claims.sql (65.05ms)17382026/09/22 10:48:47 OK 20260920000000_drop_claims.sql (37.78ms)17392026/09/22 10:48:47 goose: successfully migrated database to version: 2026092000000017402026/09/22 10:48:47 OK 1_commit_pending_closure.sql (2.01ms)17412026/09/22 10:48:47 OK 2_object_stats_trigger.sql (646.54µs)17422026/09/22 10:48:47 goose: up to current file version: 217432026-09-22 10:48:47.298 UTC [53649] ERROR: relation "goose_db_version" does not exist at character 3617442026-09-22 10:48:47.298 UTC [53649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17452026/09/22 10:48:47 INFO Received uploads request method=POST path=/api/pending_closures17462026-09-22 10:48:47.404 UTC [53661] ERROR: relation "goose_db_version" does not exist at character 3617472026-09-22 10:48:47.404 UTC [53661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17482026/09/22 10:48:47 INFO Received cleanup request method=DELETE path=/api/pending_closures17492026/09/22 10:48:47 OK 20241026095416_initial_model.sql (143.8ms)17502026/09/22 10:48:47 INFO Aborted multipart uploads count=117512026/09/22 10:48:47 OK 20251210153512_drop_unused_gin_index.sql (17.22ms)1752--- PASS: TestMultipartCleanup (2.53s)1753=== CONT TestGCTaskStore_ConflictDifferentParams1754--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1755=== CONT TestGCTaskStore_DeduplicateSameParams1756--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1757=== CONT TestRedundantMultipartUpload17582026/09/22 10:48:47 OK 20251218171726_add_pins.sql (46.9ms)17592026/09/22 10:48:47 OK 20260628120000_add_object_size_and_stats.sql (30.2ms)1760=== NAME TestOrphanedObjectsGC1761 orphaned_objects_gc_test.go:290: GC Test Summary:1762 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1763 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1764 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1765 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1766 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1767--- PASS: TestOrphanedObjectsGC (2.86s)1768=== CONT TestCompleteMultipartUpload_ErrorButObjectExists17692026/09/22 10:48:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17702026/09/22 10:48:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1771--- PASS: TestService_NativeMTLS (2.38s)1772=== CONT TestReadRedirectUsesPublicS3URL17732026/09/22 10:48:47 OK 20241026095416_initial_model.sql (166.22ms)17742026/09/22 10:48:47 OK 20260905000000_add_claims.sql (33.36ms)17752026/09/22 10:48:47 OK 20251210153512_drop_unused_gin_index.sql (25.19ms)17762026/09/22 10:48:47 OK 20260920000000_drop_claims.sql (32.11ms)17772026/09/22 10:48:47 goose: successfully migrated database to version: 2026092000000017782026/09/22 10:48:47 OK 1_commit_pending_closure.sql (1.44ms)17792026/09/22 10:48:47 OK 2_object_stats_trigger.sql (1.03ms)17802026/09/22 10:48:47 goose: up to current file version: 217812026/09/22 10:48:47 OK 20251218171726_add_pins.sql (26.58ms)17822026-09-22 10:48:47.693 UTC [53684] ERROR: relation "goose_db_version" does not exist at character 3617832026-09-22 10:48:47.693 UTC [53684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17842026/09/22 10:48:47 OK 20260628120000_add_object_size_and_stats.sql (23.25ms)17852026/09/22 10:48:47 OK 20260905000000_add_claims.sql (32.37ms)17862026/09/22 10:48:47 OK 20260920000000_drop_claims.sql (37.33ms)17872026/09/22 10:48:47 goose: successfully migrated database to version: 2026092000000017882026/09/22 10:48:47 OK 1_commit_pending_closure.sql (2ms)17892026/09/22 10:48:47 OK 2_object_stats_trigger.sql (516µs)17902026/09/22 10:48:47 goose: up to current file version: 21791--- PASS: TestMetricsInventory (2.39s)1792=== CONT TestReadProxyRangeRequest17932026/09/22 10:48:47 OK 20241026095416_initial_model.sql (177.56ms)17942026/09/22 10:48:47 OK 20251210153512_drop_unused_gin_index.sql (11.87ms)17952026/09/22 10:48:47 OK 20251218171726_add_pins.sql (28.59ms)17962026/09/22 10:48:47 OK 20260628120000_add_object_size_and_stats.sql (14.19ms)17972026/09/22 10:48:48 OK 20260905000000_add_claims.sql (54.06ms)17982026/09/22 10:48:48 OK 20260920000000_drop_claims.sql (40.11ms)17992026/09/22 10:48:48 goose: successfully migrated database to version: 2026092000000018002026/09/22 10:48:48 OK 1_commit_pending_closure.sql (2.83ms)18012026/09/22 10:48:48 OK 2_object_stats_trigger.sql (644.5µs)18022026/09/22 10:48:48 goose: up to current file version: 21803=== NAME TestNARDeduplicationMetadataUploadBug1804 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-51550-1708907945/TestNARDeduplicationMetadataUploadBug1853709312/001/store/6hrlcp43p0l44qxmamh8zr6a20j8gvjw-file1.txt18052026/09/22 10:48:48 WARN readiness check failed error="closed pool"1806--- PASS: TestService_readinessHandler (2.34s)1807=== CONT TestService_cleanupPendingClosuresHandler18082026/09/22 10:48:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18092026-09-22 10:48:48.486 UTC [53722] ERROR: relation "goose_db_version" does not exist at character 3618102026-09-22 10:48:48.486 UTC [53722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18112026/09/22 10:48:48 INFO Received uploads request method=POST path=/api/pending_closures1812--- PASS: TestService_healthCheckHandler (2.42s)1813=== CONT TestClientErrorHandling/InvalidStorePath18142026/09/22 10:48:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18152026/09/22 10:48:48 INFO Uploading 6hrlcp43p0l44qxmamh8zr6a20j8gvjw-file1.txt (160B)18162026/09/22 10:48:48 OK 20241026095416_initial_model.sql (80.15ms)18172026/09/22 10:48:48 OK 20251210153512_drop_unused_gin_index.sql (13.18ms)18182026/09/22 10:48:48 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18192026/09/22 10:48:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18202026/09/22 10:48:48 WARN Failed to register uploaded object key=6hrlcp43p0l44qxmamh8zr6a20j8gvjw.ls error="server returned 404: 404 page not found\n"18212026/09/22 10:48:48 INFO Signed narinfos id=1 count=118222026/09/22 10:48:48 OK 20251218171726_add_pins.sql (6.68ms)18232026/09/22 10:48:48 INFO Uploading 1 narinfos18242026/09/22 10:48:48 OK 20260628120000_add_object_size_and_stats.sql (47.69ms)18252026/09/22 10:48:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18262026/09/22 10:48:48 WARN Failed to register uploaded object key=6hrlcp43p0l44qxmamh8zr6a20j8gvjw.narinfo error="server returned 404: 404 page not found\n"18272026/09/22 10:48:48 INFO Completed upload id=118282026/09/22 10:48:48 INFO Upload complete. (350ms)1829=== NAME TestNARDeduplicationMetadataUploadBug1830 metadata_upload_test.go:54: Retrieved narinfo from S3:1831 StorePath: /nix/var/nix/builds/nix-51550-1708907945/TestNARDeduplicationMetadataUploadBug1853709312/001/store/6hrlcp43p0l44qxmamh8zr6a20j8gvjw-file1.txt1832 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1833 Compression: zstd1834 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1835 NarSize: 1601836 References: 1837 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1838 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1839 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1840 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18412026/09/22 10:48:48 OK 20260905000000_add_claims.sql (81.62ms)18422026/09/22 10:48:48 OK 20260920000000_drop_claims.sql (20.5ms)18432026/09/22 10:48:48 goose: successfully migrated database to version: 2026092000000018442026/09/22 10:48:48 OK 1_commit_pending_closure.sql (3.81ms)1845 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-51550-1708907945/TestNARDeduplicationMetadataUploadBug1853709312/001/store/jynpfv2k1wa8m849rinxgwlj7755bxmr-file2.txt18462026/09/22 10:48:48 OK 2_object_stats_trigger.sql (878.29µs)18472026/09/22 10:48:48 goose: up to current file version: 218482026/09/22 10:48:48 INFO Received uploads request method=POST path=/api/pending_closures18492026-09-22 10:48:48.875 UTC [53749] ERROR: relation "goose_db_version" does not exist at character 3618502026-09-22 10:48:48.875 UTC [53749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18512026/09/22 10:48:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18522026/09/22 10:48:49 INFO Received uploads request method=POST path=/api/pending_closures18532026/09/22 10:48:49 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18542026-09-22 10:48:49.010 UTC [53756] ERROR: relation "goose_db_version" does not exist at character 3618552026-09-22 10:48:49.010 UTC [53756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18562026/09/22 10:48:49 OK 20241026095416_initial_model.sql (116.96ms)18572026/09/22 10:48:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18582026/09/22 10:48:49 WARN Failed to register uploaded object key=jynpfv2k1wa8m849rinxgwlj7755bxmr.ls error="server returned 404: 404 page not found\n"18592026/09/22 10:48:49 INFO Signed narinfos id=2 count=118602026/09/22 10:48:49 INFO Uploading 1 narinfos18612026/09/22 10:48:49 OK 20251210153512_drop_unused_gin_index.sql (15.74ms)18622026/09/22 10:48:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18632026/09/22 10:48:49 WARN Failed to register uploaded object key=jynpfv2k1wa8m849rinxgwlj7755bxmr.narinfo error="server returned 404: 404 page not found\n"18642026/09/22 10:48:49 INFO Completed upload id=218652026/09/22 10:48:49 INFO Upload complete. (213ms)1866 metadata_upload_test.go:76: Retrieved narinfo from S3:1867 StorePath: /nix/var/nix/builds/nix-51550-1708907945/TestNARDeduplicationMetadataUploadBug1853709312/001/store/jynpfv2k1wa8m849rinxgwlj7755bxmr-file2.txt1868 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1869 Compression: zstd1870 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1871 NarSize: 1601872 References: 1873 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1874 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1875 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1876 {"version":1,"root":{"type":"regular","size":44}}18772026/09/22 10:48:49 OK 20251218171726_add_pins.sql (34.73ms)18782026/09/22 10:48:49 OK 20260628120000_add_object_size_and_stats.sql (50.21ms)1879--- PASS: TestNARDeduplicationMetadataUploadBug (3.40s)1880=== CONT TestClientErrorHandling/InvalidAuthToken18812026/09/22 10:48:49 OK 20260905000000_add_claims.sql (11.67ms)18822026/09/22 10:48:49 INFO Received uploads request method=POST path=/api/pending_closures18832026/09/22 10:48:49 INFO Received uploads request method=POST path=/api/pending_closures18842026/09/22 10:48:49 INFO Received uploads request method=POST path=/api/pending_closures18852026/09/22 10:48:49 OK 20260920000000_drop_claims.sql (52.88ms)18862026/09/22 10:48:49 goose: successfully migrated database to version: 2026092000000018872026/09/22 10:48:49 OK 1_commit_pending_closure.sql (1.82ms)18882026/09/22 10:48:49 OK 2_object_stats_trigger.sql (558.88µs)18892026/09/22 10:48:49 goose: up to current file version: 218902026-09-22 10:48:49.200 UTC [53761] ERROR: relation "goose_db_version" does not exist at character 3618912026-09-22 10:48:49.200 UTC [53761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18922026/09/22 10:48:49 OK 20241026095416_initial_model.sql (240.8ms)18932026/09/22 10:48:49 OK 20251210153512_drop_unused_gin_index.sql (12.09ms)18942026/09/22 10:48:49 OK 20251218171726_add_pins.sql (15.28ms)18952026/09/22 10:48:49 OK 20260628120000_add_object_size_and_stats.sql (48.2ms)18962026-09-22 10:48:49.410 UTC [53772] ERROR: relation "goose_db_version" does not exist at character 3618972026-09-22 10:48:49.410 UTC [53772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18982026/09/22 10:48:49 OK 20241026095416_initial_model.sql (171.81ms)18992026/09/22 10:48:49 OK 20260905000000_add_claims.sql (90.17ms)19002026/09/22 10:48:49 OK 20251210153512_drop_unused_gin_index.sql (11.98ms)19012026/09/22 10:48:49 OK 20260920000000_drop_claims.sql (15.17ms)19022026/09/22 10:48:49 goose: successfully migrated database to version: 2026092000000019032026/09/22 10:48:49 INFO Received uploads request method=POST path=/api/pending_closures19042026/09/22 10:48:49 OK 20251218171726_add_pins.sql (14.39ms)19052026/09/22 10:48:49 OK 1_commit_pending_closure.sql (3.91ms)19062026/09/22 10:48:49 OK 2_object_stats_trigger.sql (646.67µs)19072026/09/22 10:48:49 goose: up to current file version: 219082026/09/22 10:48:49 OK 20260628120000_add_object_size_and_stats.sql (20.82ms)19092026/09/22 10:48:49 INFO Received uploads request method=POST path=/api/pending_closures19102026/09/22 10:48:49 OK 20260905000000_add_claims.sql (122.29ms)19112026/09/22 10:48:49 OK 20260920000000_drop_claims.sql (48.01ms)19122026/09/22 10:48:49 goose: successfully migrated database to version: 2026092000000019132026/09/22 10:48:49 OK 1_commit_pending_closure.sql (2.36ms)19142026/09/22 10:48:49 OK 2_object_stats_trigger.sql (1.22ms)19152026/09/22 10:48:49 goose: up to current file version: 219162026/09/22 10:48:49 OK 20241026095416_initial_model.sql (234.13ms)19172026/09/22 10:48:49 OK 20251210153512_drop_unused_gin_index.sql (17.17ms)19182026/09/22 10:48:49 OK 20251218171726_add_pins.sql (51.43ms)19192026/09/22 10:48:49 OK 20260628120000_add_object_size_and_stats.sql (55.85ms)19202026-09-22 10:48:49.876 UTC [53799] ERROR: relation "goose_db_version" does not exist at character 3619212026-09-22 10:48:49.876 UTC [53799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19222026-09-22 10:48:49.887 UTC [53801] ERROR: relation "goose_db_version" does not exist at character 3619232026-09-22 10:48:49.887 UTC [53801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19242026/09/22 10:48:49 OK 20260905000000_add_claims.sql (26.17ms)1925--- PASS: TestReadRedirectUsesPublicS3URL (2.27s)1926=== CONT TestClientErrorHandling/ServerNotAvailable19272026/09/22 10:48:49 OK 20260920000000_drop_claims.sql (29.37ms)19282026/09/22 10:48:49 goose: successfully migrated database to version: 2026092000000019292026/09/22 10:48:49 OK 1_commit_pending_closure.sql (1.98ms)19302026/09/22 10:48:49 OK 2_object_stats_trigger.sql (606.75µs)19312026/09/22 10:48:49 goose: up to current file version: 219322026/09/22 10:48:50 OK 20241026095416_initial_model.sql (135.37ms)19332026/09/22 10:48:50 OK 20251210153512_drop_unused_gin_index.sql (28.39ms)19342026/09/22 10:48:50 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19352026/09/22 10:48:50 OK 20251218171726_add_pins.sql (50.53ms)19362026/09/22 10:48:50 OK 20241026095416_initial_model.sql (232.87ms)19372026/09/22 10:48:50 INFO Received uploads request method=POST path=/api/pending_closures19382026/09/22 10:48:50 OK 20251210153512_drop_unused_gin_index.sql (16.18ms)19392026/09/22 10:48:50 OK 20260628120000_add_object_size_and_stats.sql (39.13ms)19402026/09/22 10:48:50 OK 20251218171726_add_pins.sql (27.19ms)19412026/09/22 10:48:50 OK 20260905000000_add_claims.sql (18.14ms)19422026/09/22 10:48:50 OK 20260920000000_drop_claims.sql (16.35ms)19432026/09/22 10:48:50 goose: successfully migrated database to version: 2026092000000019442026/09/22 10:48:50 OK 20260628120000_add_object_size_and_stats.sql (16.5ms)19452026/09/22 10:48:50 OK 1_commit_pending_closure.sql (2.97ms)19462026/09/22 10:48:50 OK 2_object_stats_trigger.sql (1.25ms)19472026/09/22 10:48:50 goose: up to current file version: 219482026/09/22 10:48:50 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.908192ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19492026/09/22 10:48:50 OK 20260905000000_add_claims.sql (36.29ms)19502026/09/22 10:48:50 OK 20260920000000_drop_claims.sql (56.61ms)19512026/09/22 10:48:50 goose: successfully migrated database to version: 2026092000000019522026/09/22 10:48:50 OK 1_commit_pending_closure.sql (1.9ms)19532026/09/22 10:48:50 OK 2_object_stats_trigger.sql (543.25µs)19542026/09/22 10:48:50 goose: up to current file version: 219552026/09/22 10:48:50 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.454388ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1956--- PASS: TestReadProxyRangeRequest (2.61s)1957=== CONT TestCacheConfigHandler/full_config,_no_issuer1958=== CONT TestCacheConfigHandler/no_signing_keys1959=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1960=== CONT TestCacheConfigHandler/no_cache_url_configured1961--- PASS: TestCacheConfigHandler (0.00s)1962 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1963 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1964 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1965 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1966=== CONT TestService_RequireScope_OIDC/builder_may_write1967=== CONT TestService_RequireScope_OIDC/static_token_may_admin1968=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1969=== CONT TestService_RequireScope_OIDC/writer_implies_read1970=== CONT TestService_RequireScope_OIDC/reader_may_read1971=== CONT TestService_RequireScope_OIDC/ops_may_not_write1972=== CONT TestService_RequireScope_OIDC/reader_may_not_write1973=== CONT TestService_RequireScope_OIDC/ops_may_admin1974=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1975=== CONT TestService_RequireScope_OIDC/static_token_may_write1976=== CONT TestResolveDBConnectionString/flag_wins1977=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1978=== CONT TestResolveDBConnectionString/nothing_configured1979=== CONT TestResolveDBConnectionString/missing_file_is_an_error1980=== CONT TestResolveDBConnectionString/file_when_flag_empty1981=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1982=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19832026/09/22 10:48:50 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]1984=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1985=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19862026/09/22 10:48:50 WARN Authentication failed token_preview=eyJhbGciOi...3vwqhonDEA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1987=== CONT TestIsValidCachePath/narinfo1988=== CONT TestIsValidCachePath/index.html1989=== CONT TestIsValidCachePath/short_hash1990=== CONT TestIsValidCachePath/wrong_extension1991=== CONT TestIsValidCachePath/leading_slash1992=== CONT TestIsValidCachePath/empty1993=== CONT TestIsValidCachePath/random_path1994=== CONT TestIsValidCachePath/invalid_char_u1995=== CONT TestIsValidCachePath/invalid_char_e1996=== CONT TestIsValidCachePath/traversal_in_middle1997=== CONT TestIsValidCachePath/traversal_parent1998=== CONT TestIsValidCachePath/nar_uncompressed1999=== CONT TestIsValidCachePath/nix-cache-info2000=== CONT TestIsValidCachePath/realisation2001=== CONT TestIsValidCachePath/log2002=== CONT TestIsValidCachePath/ls2003=== CONT TestIsValidCachePath/nar_xz2004=== CONT TestIsValidCachePath/nar_bz22005=== CONT TestIsValidCachePath/nar_zst2006=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2007--- PASS: TestIsValidCachePath (0.01s)2008 --- PASS: TestIsValidCachePath/narinfo (0.00s)2009 --- PASS: TestIsValidCachePath/index.html (0.00s)2010 --- PASS: TestIsValidCachePath/short_hash (0.00s)2011 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2012 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2013 --- PASS: TestIsValidCachePath/empty (0.00s)2014 --- PASS: TestIsValidCachePath/random_path (0.00s)2015 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2016 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2017 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2018 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2019 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2020 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2021 --- PASS: TestIsValidCachePath/realisation (0.00s)2022 --- PASS: TestIsValidCachePath/log (0.00s)2023 --- PASS: TestIsValidCachePath/ls (0.00s)2024 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2025 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2026 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2027 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2028=== CONT TestParseSingleRange/none2029=== CONT TestParseSingleRange/open-ended2030=== CONT TestParseSingleRange/start_far_past_EOF2031=== CONT TestParseSingleRange/start_past_EOF2032=== CONT TestParseSingleRange/single_byte2033=== CONT TestParseSingleRange/suffix_exceeds_size2034=== CONT TestParseSingleRange/suffix2035=== CONT TestParseSingleRange/end_clamped_to_size2036=== CONT TestParseSingleRange/malformed_both_empty2037=== CONT TestParseSingleRange/closed2038=== CONT TestParseSingleRange/malformed_end_before_start2039=== CONT TestParseSingleRange/multi-range_ignored2040=== CONT TestParseSingleRange/malformed_no_dash2041=== CONT TestParseSingleRange/unknown_unit2042--- PASS: TestParseSingleRange (0.00s)2043 --- PASS: TestParseSingleRange/none (0.00s)2044 --- PASS: TestParseSingleRange/open-ended (0.00s)2045 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2046 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2047 --- PASS: TestParseSingleRange/single_byte (0.00s)2048 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2049 --- PASS: TestParseSingleRange/suffix (0.00s)2050 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2051 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2052 --- PASS: TestParseSingleRange/closed (0.00s)2053 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2054 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2055 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2056 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2057=== CONT TestServerTLSConfig/no_client_CA2058=== CONT TestServerTLSConfig/not_a_PEM_file20592026/09/22 10:48:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20602026/09/22 10:48:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjA3M2E2M2YtNWUyYy00ODg1LWFhZGItNDBiMGQzNjQ3NGY3LjM1M2VjMjdjLWMxNmQtNDc3OS05ODc1LTc0ZmVhY2Q4ZWU5MHgxNzkwMDc0MTMwMjEwODM2MDAw2061--- PASS: TestService_AuthMiddleware_OIDC (1.02s)2062 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2063 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2064 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2065 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2066--- PASS: TestService_RequireScope_OIDC (0.72s)2067 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2068 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2069 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2070 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2071 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2072 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2073 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2074 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2075 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2077--- PASS: TestResolveDBConnectionString (0.02s)2078 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2079 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2080 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2081 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2082 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20832026/09/22 10:48:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjA3M2E2M2YtNWUyYy00ODg1LWFhZGItNDBiMGQzNjQ3NGY3LjM1M2VjMjdjLWMxNmQtNDc3OS05ODc1LTc0ZmVhY2Q4ZWU5MHgxNzkwMDc0MTMwMjEwODM2MDAw parts=12084--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.92s)2085=== CONT TestServerTLSConfig/missing_CA_file2086=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20872026/09/22 10:48:50 INFO Received request for more parts method=POST path=/2088=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20892026/09/22 10:48:50 INFO Received uploads request method=POST path=/2090=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20912026/09/22 10:48:50 INFO Received complete multipart upload request method=POST path=/2092=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20932026/09/22 10:48:50 INFO Received uploads request method=POST path=/2094--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2095 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2096 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2097 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2098 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2099=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21002026/09/22 10:48:50 INFO Received uploads request method=POST path=/2101--- PASS: TestServerTLSConfig (0.00s)2102 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2103 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2104 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.04s)2105=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21062026/09/22 10:48:50 INFO Received complete multipart upload request method=POST path=/2107=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21082026/09/22 10:48:50 INFO Received request for more parts method=POST path=/2109=== CONT TestIsValidUploadKey/narinfo2110=== CONT TestIsValidUploadKey/realisation_plus_in_output2111=== CONT TestIsValidUploadKey/realisation2112=== CONT TestIsValidUploadKey/build_log_equals2113=== CONT TestIsValidUploadKey/build_log_question_mark2114=== CONT TestIsValidUploadKey/build_log_plus_in_name2115=== CONT TestIsValidUploadKey/build_log_home-manager_file2116=== CONT TestIsValidUploadKey/build_log2117=== CONT TestIsValidUploadKey/listing2118=== CONT TestIsValidUploadKey/nar_plain2119=== CONT TestIsValidUploadKey/nar_xz2120=== CONT TestIsValidUploadKey/nix-cache-info2121=== CONT TestIsValidUploadKey/nar_zst2122=== CONT TestIsValidUploadKey/traversal2123=== CONT TestIsValidUploadKey/unknown_type2124=== CONT TestIsValidUploadKey/empty_key2125=== CONT TestIsValidUploadKey/absolute2126=== CONT TestIsValidUploadKey/traversal_nar2127=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2128=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2129=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2130=== CONT TestIsValidUploadKey/index.html2131--- PASS: TestIsValidUploadKey (0.00s)2132 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2133 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2134 --- PASS: TestIsValidUploadKey/realisation (0.00s)2135 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2136 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2137 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2138 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2139 --- PASS: TestIsValidUploadKey/build_log (0.00s)2140 --- PASS: TestIsValidUploadKey/listing (0.00s)2141 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2142 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2143 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2144 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2145 --- PASS: TestIsValidUploadKey/traversal (0.00s)2146 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2147 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2148 --- PASS: TestIsValidUploadKey/absolute (0.00s)2149 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2150 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2151 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2152 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2153 --- PASS: TestIsValidUploadKey/index.html (0.00s)2154=== CONT TestProxyWriteTimeout/narinfo2155=== CONT TestProxyWriteTimeout/10_GiB_nar2156=== CONT TestProxyWriteTimeout/unknown_size2157=== CONT TestProxyWriteTimeout/1_GiB_nar2158--- PASS: TestProxyWriteTimeout (0.00s)2159 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2160 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2161 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2162 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)21632026/09/22 10:48:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21642026-09-22 10:48:50.763 UTC [53845] ERROR: relation "goose_db_version" does not exist at character 3621652026-09-22 10:48:50.763 UTC [53845] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21662026/09/22 10:48:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.196086ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21672026/09/22 10:48:50 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjA3M2E2M2YtNWUyYy00ODg1LWFhZGItNDBiMGQzNjQ3NGY3LjJjMzY5NjRhLTIzN2UtNGY5NC04NTYxLTA2NTQ4ZGRlNDhjYXgxNzkwMDc0MTI4OTAyMzU3MDAw parts=1021682026/09/22 10:48:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21692026/09/22 10:48:50 INFO Completed upload id=121702026/09/22 10:48:50 INFO Received uploads request method=POST path=/api/pending_closures21712026/09/22 10:48:50 INFO Received uploads request method=POST path=/api/pending_closures21722026/09/22 10:48:50 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo21732026/09/22 10:48:50 WARN Found objects in DB but missing from S3, will re-upload count=12174--- PASS: TestService_verifyS3Integrity (4.34s)2175--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2176 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2177 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2178 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.35s)21792026/09/22 10:48:50 OK 20241026095416_initial_model.sql (129.25ms)21802026/09/22 10:48:50 OK 20251210153512_drop_unused_gin_index.sql (16.78ms)21812026/09/22 10:48:50 OK 20251218171726_add_pins.sql (38.89ms)21822026/09/22 10:48:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21832026/09/22 10:48:51 INFO Received cleanup request method=DELETE path=/api/pending_closures21842026/09/22 10:48:51 INFO Aborted multipart uploads count=021852026/09/22 10:48:51 INFO Received uploads request method=POST path=/api/pending_closures21862026/09/22 10:48:51 OK 20260628120000_add_object_size_and_stats.sql (60.81ms)21872026/09/22 10:48:51 OK 20260905000000_add_claims.sql (27.55ms)21882026/09/22 10:48:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjA3M2E2M2YtNWUyYy00ODg1LWFhZGItNDBiMGQzNjQ3NGY3LmFhZWUyZDgxLWY3NDYtNDI3My05MDYyLTYzYWY5NDEyM2U0N3gxNzkwMDc0MTI5MjIwNjMwMDAw parts=1021892026/09/22 10:48:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21902026/09/22 10:48:51 INFO Completed upload id=121912026/09/22 10:48:51 INFO Received cleanup request method=DELETE path=/api/pending_closures21922026/09/22 10:48:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000021932026/09/22 10:48:51 INFO Received uploads request method=POST path=/api/pending_closures21942026/09/22 10:48:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures21952026/09/22 10:48:51 INFO Aborted multipart uploads count=021962026/09/22 10:48:51 INFO Aborted multipart uploads count=121972026/09/22 10:48:51 OK 20260920000000_drop_claims.sql (13.21ms)21982026/09/22 10:48:51 goose: successfully migrated database to version: 2026092000000021992026/09/22 10:48:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22002026-09-22 10:48:51.081 UTC [53799] ERROR: Closure does not exist: id=122012026-09-22 10:48:51.081 UTC [53799] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE22022026-09-22 10:48:51.081 UTC [53799] STATEMENT: -- name: CommitPendingClosure :exec2203 SELECT commit_pending_closure($1::bigint)2204 2205--- PASS: TestService_cleanupPendingClosuresHandler (2.76s)22062026/09/22 10:48:51 OK 1_commit_pending_closure.sql (3.26ms)22072026/09/22 10:48:51 OK 2_object_stats_trigger.sql (984.08µs)22082026/09/22 10:48:51 goose: up to current file version: 222092026/09/22 10:48:51 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=022102026/09/22 10:48:51 INFO Vacuumed table table=pending_closures22112026/09/22 10:48:51 INFO Vacuumed table table=pending_objects22122026/09/22 10:48:51 INFO Vacuumed table table=multipart_uploads22132026/09/22 10:48:51 INFO Vacuumed table table=closures22142026/09/22 10:48:51 INFO Vacuumed table table=objects22152026/09/22 10:48:51 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002216--- PASS: TestService_createPendingClosureHandler (4.05s)22172026/09/22 10:48:51 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22182026/09/22 10:48:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22192026/09/22 10:48:51 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22202026/09/22 10:48:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjA3M2E2M2YtNWUyYy00ODg1LWFhZGItNDBiMGQzNjQ3NGY3LjNkMDlmYmQ1LTQwMWYtNGNkOC1iY2JjLTdiZWMwMzU1NmJiNHgxNzkwMDc0MTI5NTI0MTM2MDAw parts=122221--- PASS: TestRedundantMultipartUpload (4.01s)22222026/09/22 10:48:51 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22232026/09/22 10:48:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.653970349s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2224=== NAME TestOrphanedObjectsGCStressTest2225 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2226 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2227 orphaned_objects_gc_test.go:509: Stress test completed successfully:2228 orphaned_objects_gc_test.go:510: - Active objects preserved: 202229 orphaned_objects_gc_test.go:511: - Objects deleted: 2102230 orphaned_objects_gc_test.go:512: - Total GC'd: 2102231--- PASS: TestOrphanedObjectsGCStressTest (7.87s)22322026/09/22 10:48:53 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/09/22 10:48:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.3229ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/09/22 10:48:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=397.796504ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/09/22 10:48:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=746.937305ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/09/22 10:48:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.587353827s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22372026/09/22 10:48:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"22382026/09/22 10:48:56 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22392026/09/22 10:48:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.097453ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22402026/09/22 10:48:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.706993ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22412026/09/22 10:48:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=740.213216ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22422026/09/22 10:48:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.519555852s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2243--- PASS: TestClientErrorHandling (0.00s)2244 --- PASS: TestClientErrorHandling/InvalidStorePath (2.24s)2245 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.46s)2246 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.44s)2247PASS2248{"timestamp":"2026-09-22T10:48:59.331968Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58716","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}22492026-09-22 10:48:59.394 UTC [52203] LOG: received smart shutdown request22502026-09-22 10:48:59.395 UTC [52203] LOG: background worker "logical replication launcher" (PID 52213) exited with exit code 122512026-09-22 10:48:59.403 UTC [52208] LOG: shutting down22522026-09-22 10:48:59.403 UTC [52208] LOG: checkpoint starting: shutdown immediate22532026-09-22 10:49:00.470 UTC [52208] LOG: checkpoint complete: wrote 12986 buffers (79.3%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.721 s, sync=0.340 s, total=1.067 s; sync files=19072, longest=0.001 s, average=0.001 s; distance=264771 kB, estimate=264771 kB; lsn=0/11A1DCC8, redo lsn=0/11A1DCC822542026-09-22 10:49:00.494 UTC [52203] LOG: database system is shut down2255Running OIDC tests...2256=== RUN TestAudienceForIssuer2257=== PAUSE TestAudienceForIssuer2258=== RUN TestGlobMatch2259=== PAUSE TestGlobMatch2260=== RUN TestValidateToken_ValidToken2261=== PAUSE TestValidateToken_ValidToken2262=== RUN TestValidateToken_WrongAudience2263=== PAUSE TestValidateToken_WrongAudience2264=== RUN TestValidateToken_Expired2265=== PAUSE TestValidateToken_Expired2266=== RUN TestValidateToken_BoundClaimsMismatch2267=== PAUSE TestValidateToken_BoundClaimsMismatch2268=== RUN TestValidateToken_BoundSubjectMismatch2269=== PAUSE TestValidateToken_BoundSubjectMismatch2270=== RUN TestValidateToken_MultipleProviders2271=== PAUSE TestValidateToken_MultipleProviders2272=== RUN TestValidateToken_NoMatchingProvider2273=== PAUSE TestValidateToken_NoMatchingProvider2274=== RUN TestValidateToken_KubernetesServiceAccount2275=== PAUSE TestValidateToken_KubernetesServiceAccount2276=== RUN TestNewValidator_KubernetesRequiresCA2277=== PAUSE TestNewValidator_KubernetesRequiresCA2278=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2279=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2280=== RUN TestPins_ReservedForMatchingRule2281=== PAUSE TestPins_ReservedForMatchingRule2282=== RUN TestPins_TopLevelShorthand2283=== PAUSE TestPins_TopLevelShorthand2284=== RUN TestPins_ConfigValidation2285=== PAUSE TestPins_ConfigValidation2286=== RUN TestScopes_LegacyProviderDefaultsToWrite2287=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2288=== RUN TestScopes_Rules2289=== PAUSE TestScopes_Rules2290=== RUN TestScopes_ConfigValidation2291=== PAUSE TestScopes_ConfigValidation2292=== CONT TestAudienceForIssuer2293--- PASS: TestAudienceForIssuer (0.00s)2294=== CONT TestValidateToken_NoMatchingProvider2295=== CONT TestValidateToken_KubernetesServiceAccount2296=== CONT TestValidateToken_Expired2297=== CONT TestPins_ConfigValidation2298=== CONT TestScopes_Rules2299=== CONT TestPins_ReservedForMatchingRule2300=== CONT TestValidateToken_ValidToken2301=== CONT TestScopes_ConfigValidation2302=== CONT TestValidateToken_BoundSubjectMismatch2303=== CONT TestValidateToken_WrongAudience2304--- PASS: TestPins_ConfigValidation (0.00s)2305=== CONT TestScopes_LegacyProviderDefaultsToWrite2306--- PASS: TestScopes_ConfigValidation (0.00s)2307=== CONT TestGlobMatch2308=== RUN TestGlobMatch/foo_foo2309=== PAUSE TestGlobMatch/foo_foo2310=== RUN TestGlobMatch/foo_bar2311=== PAUSE TestGlobMatch/foo_bar2312=== RUN TestGlobMatch/*_2313=== PAUSE TestGlobMatch/*_2314=== RUN TestGlobMatch/*_anything2315=== PAUSE TestGlobMatch/*_anything2316=== RUN TestGlobMatch/foo*_foo2317=== PAUSE TestGlobMatch/foo*_foo2318=== RUN TestGlobMatch/foo*_foobar2319=== PAUSE TestGlobMatch/foo*_foobar2320=== RUN TestGlobMatch/foo*_bar2321=== PAUSE TestGlobMatch/foo*_bar2322=== RUN TestGlobMatch/*bar_bar2323=== PAUSE TestGlobMatch/*bar_bar2324=== RUN TestGlobMatch/*bar_foobar2325=== PAUSE TestGlobMatch/*bar_foobar2326=== RUN TestGlobMatch/*bar_foo2327=== PAUSE TestGlobMatch/*bar_foo2328=== RUN TestGlobMatch/foo*bar_foobar2329=== PAUSE TestGlobMatch/foo*bar_foobar2330=== RUN TestGlobMatch/foo*bar_foo123bar2331=== PAUSE TestGlobMatch/foo*bar_foo123bar2332=== RUN TestGlobMatch/foo*bar_foobarbaz2333=== PAUSE TestGlobMatch/foo*bar_foobarbaz2334=== RUN TestGlobMatch/*/*_foo/bar2335=== PAUSE TestGlobMatch/*/*_foo/bar2336=== RUN TestGlobMatch/*/*_foo2337=== PAUSE TestGlobMatch/*/*_foo2338=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2339=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2340=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02341=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02342=== RUN TestGlobMatch/refs/*/main_refs/heads/main2343=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2344=== RUN TestGlobMatch/fo?_foo2345=== PAUSE TestGlobMatch/fo?_foo2346=== RUN TestGlobMatch/fo?_fo2347=== PAUSE TestGlobMatch/fo?_fo2348=== RUN TestGlobMatch/fo?_fooo2349=== PAUSE TestGlobMatch/fo?_fooo2350=== RUN TestGlobMatch/?oo_foo2351=== PAUSE TestGlobMatch/?oo_foo2352=== RUN TestGlobMatch/?oo_boo2353=== PAUSE TestGlobMatch/?oo_boo2354=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2355=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2356=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2357=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2358=== CONT TestValidateToken_MultipleProviders23592026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58991/oidc2360--- PASS: TestValidateToken_WrongAudience (0.02s)2361=== CONT TestPins_TopLevelShorthand23622026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58993/oidc23632026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58996/oidc2364--- PASS: TestValidateToken_ValidToken (0.03s)2365=== CONT TestValidateToken_BoundClaimsMismatch2366--- PASS: TestScopes_Rules (0.04s)2367=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23682026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58998/oidc2369--- PASS: TestValidateToken_Expired (0.04s)2370=== CONT TestNewValidator_KubernetesRequiresCA23712026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59000/oidc23722026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59002/oidc2373--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2374=== CONT TestGlobMatch/foo_foo2375=== CONT TestGlobMatch/*/*_foo/bar2376=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2378=== CONT TestGlobMatch/?oo_boo2379=== CONT TestGlobMatch/?oo_foo2380=== CONT TestGlobMatch/fo?_fooo2381=== CONT TestGlobMatch/fo?_fo2382=== CONT TestGlobMatch/fo?_foo2383=== CONT TestGlobMatch/refs/*/main_refs/heads/main2384=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02385=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2386=== CONT TestGlobMatch/*/*_foo2387=== CONT TestGlobMatch/*bar_bar2388=== CONT TestGlobMatch/foo*bar_foobarbaz2389=== CONT TestGlobMatch/foo*bar_foo123bar2390=== CONT TestGlobMatch/foo*bar_foobar2391=== CONT TestGlobMatch/*bar_foo2392=== CONT TestGlobMatch/*bar_foobar2393=== CONT TestGlobMatch/foo*_foo2394=== CONT TestGlobMatch/foo*_bar2395=== CONT TestGlobMatch/foo*_foobar2396=== CONT TestGlobMatch/*_2397=== CONT TestGlobMatch/*_anything2398=== CONT TestGlobMatch/foo_bar2399--- PASS: TestGlobMatch (0.00s)2400 --- PASS: TestGlobMatch/foo_foo (0.00s)2401 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2402 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2403 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2404 --- PASS: TestGlobMatch/?oo_boo (0.00s)2405 --- PASS: TestGlobMatch/?oo_foo (0.00s)2406 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2407 --- PASS: TestGlobMatch/fo?_fo (0.00s)2408 --- PASS: TestGlobMatch/fo?_foo (0.00s)2409 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2411 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2412 --- PASS: TestGlobMatch/*/*_foo (0.00s)2413 --- PASS: TestGlobMatch/*bar_bar (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2415 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2416 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2417 --- PASS: TestGlobMatch/*bar_foo (0.00s)2418 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2419 --- PASS: TestGlobMatch/foo*_foo (0.00s)2420 --- PASS: TestGlobMatch/foo*_bar (0.00s)2421 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2422 --- PASS: TestGlobMatch/*_ (0.00s)2423 --- PASS: TestGlobMatch/*_anything (0.00s)2424 --- PASS: TestGlobMatch/foo_bar (0.00s)2425--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)24262026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59004/oidc24272026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59007/oidc24282026/09/22 10:49:01 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232429--- PASS: TestPins_ReservedForMatchingRule (0.07s)2430--- PASS: TestPins_TopLevelShorthand (0.04s)2431--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)24322026/09/22 10:49:01 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:590112433--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)24342026/09/22 10:49:01 http: TLS handshake error from 127.0.0.1:59014: remote error: tls: bad certificate2435--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)24362026/09/22 10:49:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59006/oidc2437--- PASS: TestValidateToken_NoMatchingProvider (0.09s)24382026/09/22 10:49:01 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59019/oidc24392026/09/22 10:49:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58995/oidc2440--- PASS: TestValidateToken_MultipleProviders (0.12s)24412026/09/22 10:49:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59022/oidc2442--- PASS: TestValidateToken_BoundClaimsMismatch (0.15s)2443PASS2444Running hook tests...2445=== RUN TestSendPathsEmpty2446=== PAUSE TestSendPathsEmpty2447=== RUN TestQueueEnqueueAndFetch2448=== PAUSE TestQueueEnqueueAndFetch2449=== RUN TestQueueDeduplication2450=== PAUSE TestQueueDeduplication2451=== RUN TestQueueRemove2452=== PAUSE TestQueueRemove2453=== RUN TestQueueFetchBatchLimit2454=== PAUSE TestQueueFetchBatchLimit2455=== RUN TestQueueRetryMovesToBack2456=== PAUSE TestQueueRetryMovesToBack2457=== RUN TestQueueFetchRemoveLifecycle2458=== PAUSE TestQueueFetchRemoveLifecycle2459=== RUN TestQueueConcurrentWriters2460=== PAUSE TestQueueConcurrentWriters2461=== RUN TestQueueRemoveLargeClosure2462=== PAUSE TestQueueRemoveLargeClosure2463=== RUN TestServerClientIntegration2464=== PAUSE TestServerClientIntegration2465=== RUN TestServerQueueError2466=== PAUSE TestServerQueueError2467=== RUN TestGetListenerSocketActivation2468 server_test.go:210: === RUN TestGetListenerSocketActivation2469 --- PASS: TestGetListenerSocketActivation (0.00s)2470 PASS2471 2472--- PASS: TestGetListenerSocketActivation (0.01s)2473=== RUN TestDrainIsolatesPoisonPath2474=== PAUSE TestDrainIsolatesPoisonPath2475=== RUN TestRunNotBlockedByPoisonHead2476=== PAUSE TestRunNotBlockedByPoisonHead2477=== RUN TestDrainGivesUpWhenServerDown2478=== PAUSE TestDrainGivesUpWhenServerDown2479=== RUN TestFailedPathPrunedByLaterClosure2480=== PAUSE TestFailedPathPrunedByLaterClosure2481=== RUN TestWorkerUploadsAndRemoves2482=== PAUSE TestWorkerUploadsAndRemoves2483=== RUN TestWorkerSkipsGCdPaths2484=== PAUSE TestWorkerSkipsGCdPaths2485=== RUN TestWorkerPrunesClosureDeps2486=== PAUSE TestWorkerPrunesClosureDeps2487=== RUN TestDrainTimeout2488=== PAUSE TestDrainTimeout2489=== CONT TestSendPathsEmpty2490=== CONT TestDrainGivesUpWhenServerDown2491--- PASS: TestSendPathsEmpty (0.00s)2492=== CONT TestQueueFetchRemoveLifecycle2493=== CONT TestQueueRetryMovesToBack2494=== CONT TestQueueConcurrentWriters2495=== CONT TestQueueRemove2496=== CONT TestWorkerSkipsGCdPaths2497=== CONT TestServerQueueError2498=== CONT TestRunNotBlockedByPoisonHead2499=== CONT TestDrainIsolatesPoisonPath2500=== CONT TestQueueDeduplication25012026/09/22 10:49:01 ERROR Failed to queue paths error="permission denied" count=12502--- PASS: TestServerQueueError (0.00s)2503=== CONT TestWorkerUploadsAndRemoves25042026/09/22 10:49:01 INFO Upload queue status pending=225052026/09/22 10:49:01 INFO Upload queue status pending=325062026/09/22 10:49:01 INFO Uploading batch count=125072026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=125082026/09/22 10:49:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-51550-1708907945/TestWorkerSkipsGCdPaths2106449767/002/nonexistent25092026/09/22 10:49:01 INFO Uploading batch count=12510--- PASS: TestQueueRetryMovesToBack (0.01s)2511=== CONT TestQueueEnqueueAndFetch25122026/09/22 10:49:01 INFO Upload queue status pending=225132026/09/22 10:49:01 INFO Uploading batch count=225142026/09/22 10:49:01 INFO Uploading batch count=425152026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=42516--- PASS: TestQueueRemove (0.01s)2517=== CONT TestWorkerPrunesClosureDeps25182026/09/22 10:49:01 INFO Uploading batch count=225192026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=225202026/09/22 10:49:01 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51550-1708907945/TestDrainGivesUpWhenServerDown3123600686/002/a2521--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2522=== CONT TestQueueFetchBatchLimit2523--- PASS: TestQueueDeduplication (0.01s)2524=== CONT TestFailedPathPrunedByLaterClosure25252026/09/22 10:49:01 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51550-1708907945/TestDrainIsolatesPoisonPath3603313760/002/bbb25262026/09/22 10:49:01 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51550-1708907945/TestDrainGivesUpWhenServerDown3123600686/002/b25272026/09/22 10:49:01 INFO Uploading batch count=225282026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=225292026/09/22 10:49:01 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51550-1708907945/TestDrainGivesUpWhenServerDown3123600686/002/c25302026/09/22 10:49:01 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51550-1708907945/TestDrainGivesUpWhenServerDown3123600686/002/d25312026/09/22 10:49:01 INFO Uploading batch count=125322026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=125332026/09/22 10:49:01 INFO Uploading batch count=225342026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=225352026/09/22 10:49:01 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51550-1708907945/TestDrainGivesUpWhenServerDown3123600686/002/e25362026/09/22 10:49:01 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51550-1708907945/TestDrainGivesUpWhenServerDown3123600686/002/f2537--- PASS: TestQueueEnqueueAndFetch (0.00s)2538=== CONT TestServerClientIntegration25392026/09/22 10:49:01 INFO Uploading batch count=125402026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=125412026/09/22 10:49:01 INFO Upload queue status pending=225422026/09/22 10:49:01 INFO Uploading batch count=125432026/09/22 10:49:01 ERROR Drain finished with paths left in queue remaining=1025442026/09/22 10:49:01 INFO Uploading batch count=125452026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=12546--- PASS: TestQueueFetchBatchLimit (0.00s)2547=== CONT TestQueueRemoveLargeClosure25482026/09/22 10:49:01 INFO Uploading batch count=125492026/09/22 10:49:01 ERROR Upload failed error="upload failed" count=125502026/09/22 10:49:01 ERROR Drain finished with paths left in queue remaining=12551--- PASS: TestServerClientIntegration (0.00s)2552=== CONT TestDrainTimeout25532026/09/22 10:49:01 INFO Uploading batch count=125542026/09/22 10:49:01 INFO Uploading batch count=12555--- PASS: TestDrainIsolatesPoisonPath (0.01s)2556--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2557--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)25582026/09/22 10:49:01 INFO Uploading batch count=22559--- PASS: TestWorkerSkipsGCdPaths (0.03s)2560--- PASS: TestWorkerUploadsAndRemoves (0.02s)2561--- PASS: TestWorkerPrunesClosureDeps (0.02s)2562--- PASS: TestQueueRemoveLargeClosure (0.04s)2563--- PASS: TestQueueConcurrentWriters (0.15s)25642026/09/22 10:49:01 ERROR Upload failed error="context deadline exceeded" count=225652026/09/22 10:49:01 ERROR Drain finished with paths left in queue remaining=42566--- PASS: TestDrainTimeout (0.20s)25672026/09/22 10:49:02 INFO Uploading batch count=125682026/09/22 10:49:02 INFO Uploading batch count=125692026/09/22 10:49:02 INFO Uploading batch count=125702026/09/22 10:49:02 ERROR Upload failed error="upload failed" count=125712026/09/22 10:49:02 INFO Uploading batch count=125722026/09/22 10:49:02 ERROR Upload failed error="upload failed" count=125732026/09/22 10:49:02 INFO Uploading batch count=125742026/09/22 10:49:02 ERROR Upload failed error="upload failed" count=125752026/09/22 10:49:02 INFO Uploading batch count=125762026/09/22 10:49:02 ERROR Upload failed error="upload failed" count=125772026/09/22 10:49:02 ERROR Drain finished with paths left in queue remaining=12578--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2579PASS