niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #252
· 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.05s)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 TestSetClientTLS96=== CONT TestParsePathInfoJSONMultiplePaths97=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths98=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths99=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths100=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths101=== CONT TestScriptTokenNoExpiryRerunsEveryCall102=== CONT TestClientSignaturesByStorePath103--- PASS: TestClientSignaturesByStorePath (0.00s)104=== CONT TestStreamPushReportsSignatures105=== CONT TestScriptTokenEmptyCommand106--- PASS: TestScriptTokenEmptyCommand (0.00s)107=== CONT TestStreamPushRequestLine108=== CONT TestScriptTokenScriptFails109=== CONT TestScriptTokenBadJSON110=== CONT TestScriptTokenEmptyToken111=== CONT TestScriptTokenCachesUntilRefresh112=== CONT TestStreamPushReportsEveryPath1132026/09/22 11:04:15 ERROR Upload failed error=boom count=1114--- PASS: TestStreamPushReportsEveryPath (0.00s)115=== CONT TestStreamPushGivesUpOnDeadServer1162026/09/22 11:04:15 ERROR Upload failed error=boom count=11172026/09/22 11:04:15 ERROR Upload failed error="connection refused" count=201182026/09/22 11:04:15 ERROR Server seems unavailable, giving up on batch untried=17119--- PASS: TestStreamPushReportsSignatures (0.00s)120=== CONT TestStreamPushIsolatesFailures121--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)122=== CONT TestStreamPushBatchesUnderLoad1232026/09/22 11:04:15 ERROR Upload failed error="bad path" count=3124--- PASS: TestStreamPushIsolatesFailures (0.00s)125=== CONT TestResolveStorePath126--- PASS: TestScriptTokenScriptFails (0.00s)127=== CONT TestShellSplitErrors128--- PASS: TestShellSplitErrors (0.00s)129=== CONT TestShellSplit130--- PASS: TestShellSplit (0.00s)131=== CONT TestDoWithRetry_BodyReplayedViaGetBody132--- PASS: TestDoServerRequestAttachesToken (0.01s)133=== CONT TestRateLimiterFeedback134=== RUN TestRateLimiterFeedback/429_enables_limiter135=== PAUSE TestRateLimiterFeedback/429_enables_limiter136=== RUN TestRateLimiterFeedback/503_enables_limiter137=== PAUSE TestRateLimiterFeedback/503_enables_limiter138=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter139=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter140=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter141=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter142=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1432026/09/22 11:04:15 WARN Rate limiter enabled after throttle name=server-test rate=5144--- PASS: TestResolveStorePath (0.00s)145=== CONT TestDumpPathSingleFile1462026/09/22 11:04:15 WARN Rate limiter enabled after throttle name=server-test rate=51472026/09/22 11:04:15 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:628401482026/09/22 11:04:15 WARN Rate limiter backed off name=server-test rate=51492026/09/22 11:04:15 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:62840150--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)151=== RUN TestSetClientTLS/rejects_connection_without_client_cert152=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert153=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA154=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA155=== RUN TestSetClientTLS/preserves_debug_logging_transport156=== PAUSE TestSetClientTLS/preserves_debug_logging_transport157=== CONT TestParsePathInfoJSON158=== CONT TestPathInfoHashCompatibility159=== RUN TestParsePathInfoJSON/Nix_format160=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)161=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)162=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon163=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon164=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI165=== PAUSE TestParsePathInfoJSON/Nix_format166=== RUN TestParsePathInfoJSON/Lix_format167=== PAUSE TestParsePathInfoJSON/Lix_format168=== RUN TestParsePathInfoJSON/empty_input169=== PAUSE TestParsePathInfoJSON/empty_input170=== RUN TestParsePathInfoJSON/whitespace_only171=== PAUSE TestParsePathInfoJSON/whitespace_only172=== RUN TestParsePathInfoJSON/invalid_JSON173=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI174=== PAUSE TestParsePathInfoJSON/invalid_JSON175=== CONT TestGetStorePathHash176=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512177=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512178=== RUN TestGetStorePathHash/valid_store_path179=== CONT TestConvertHashToNix32180=== RUN TestConvertHashToNix32/SRI_format_to_Nix32181=== PAUSE TestGetStorePathHash/valid_store_path182=== RUN TestGetStorePathHash/basename_without_hyphen_should_error183=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32184=== RUN TestConvertHashToNix32/already_Nix32_format185=== PAUSE TestConvertHashToNix32/already_Nix32_format186=== RUN TestConvertHashToNix32/invalid_format187=== PAUSE TestConvertHashToNix32/invalid_format188=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error189=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error190=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error191=== CONT TestEncodeNixBase32WithRealHash192--- PASS: TestEncodeNixBase32WithRealHash (0.00s)193=== CONT TestEncodeNixBase32194=== RUN TestEncodeNixBase32/test_string_hash195=== PAUSE TestEncodeNixBase32/test_string_hash196=== RUN TestEncodeNixBase32/empty_input197=== PAUSE TestEncodeNixBase32/empty_input198=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error199=== CONT TestDumpPathWriterError200=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error201=== CONT TestPathInfoCACompatibility202=== RUN TestPathInfoCACompatibility/null_ca_field203=== PAUSE TestPathInfoCACompatibility/null_ca_field204=== RUN TestPathInfoCACompatibility/old_string_format_-_text205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text206=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive207=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive208=== RUN TestPathInfoCACompatibility/new_structured_format_-_text209=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text210=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method211=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method212=== CONT TestFileTokenReadsAndCaches213--- PASS: TestFileTokenReadsAndCaches (0.00s)214=== CONT TestFileTokenEmpty215--- PASS: TestScriptTokenBadJSON (0.01s)216=== CONT TestFileTokenMissing217--- PASS: TestFileTokenMissing (0.00s)218=== CONT TestUploadMultipart_PartsInParallel219--- PASS: TestScriptTokenEmptyToken (0.01s)220=== CONT TestDumpPathMatchesNix221--- PASS: TestFileTokenEmpty (0.00s)222=== CONT TestUploadMultipart_SupersededByPeer223=== RUN TestUploadMultipart_SupersededByPeer/exists224=== PAUSE TestUploadMultipart_SupersededByPeer/exists225=== RUN TestUploadMultipart_SupersededByPeer/missing226=== PAUSE TestUploadMultipart_SupersededByPeer/missing227=== CONT TestPartSizeForNAR228=== RUN TestPartSizeForNAR/zero_stays_at_minimum229=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum230=== RUN TestPartSizeForNAR/small_stays_at_minimum231=== PAUSE TestPartSizeForNAR/small_stays_at_minimum232=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum233=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum234=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts235=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts236=== RUN TestPartSizeForNAR/1_TiB237=== PAUSE TestPartSizeForNAR/1_TiB238=== RUN TestPartSizeForNAR/5_TiB_S3_max_object239=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object240=== RUN TestPartSizeForNAR/capped_at_5_GiB241=== PAUSE TestPartSizeForNAR/capped_at_5_GiB242=== CONT TestCaseHackSuffix243--- PASS: TestStreamPushRequestLine (0.02s)244=== CONT TestFilterOversizedClosures245=== RUN TestFilterOversizedClosures/no_limit_keeps_everything246=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything247=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped248=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped249=== RUN TestFilterOversizedClosures/all_closures_skipped250=== PAUSE TestFilterOversizedClosures/all_closures_skipped251=== CONT TestRegisterUploadedObjectReusesConnections252--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)253=== CONT TestSetClientTLSErrors254=== RUN TestSetClientTLSErrors/missing_cert_file255=== PAUSE TestSetClientTLSErrors/missing_cert_file256=== RUN TestSetClientTLSErrors/missing_key_file257=== PAUSE TestSetClientTLSErrors/missing_key_file258=== RUN TestSetClientTLSErrors/missing_ca_file259=== PAUSE TestSetClientTLSErrors/missing_ca_file260=== RUN TestSetClientTLSErrors/invalid_ca_file261=== PAUSE TestSetClientTLSErrors/invalid_ca_file262=== CONT TestStaticToken263--- PASS: TestStaticToken (0.00s)264=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths265=== CONT TestSetClientTLSDoesNotMutateDefaultTransport266--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)267=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths268--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)269 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)271=== CONT TestRateLimiterFeedback/429_enables_limiter2722026/09/22 11:04:15 WARN Rate limiter enabled after throttle name=server-test rate=52732026/09/22 11:04:15 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:629152742026/09/22 11:04:15 WARN Rate limiter backed off name=server-test rate=5275=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter276--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)277=== CONT TestRateLimiterFeedback/503_enables_limiter2782026/09/22 11:04:15 WARN Rate limiter enabled after throttle name=server-test rate=52792026/09/22 11:04:15 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:62919280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2812026/09/22 11:04:15 WARN Rate limiter backed off name=server-test rate=5282=== CONT TestSetClientTLS/rejects_connection_without_client_cert283--- PASS: TestRateLimiterFeedback (0.00s)284 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)285 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)286 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)287 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)288=== CONT TestSetClientTLS/preserves_debug_logging_transport289--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)290=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA291=== CONT TestParsePathInfoJSON/Nix_format292=== CONT TestParsePathInfoJSON/invalid_JSON293=== CONT TestParsePathInfoJSON/whitespace_only294=== CONT TestParsePathInfoJSON/empty_input295=== CONT TestParsePathInfoJSON/Lix_format296--- PASS: TestParsePathInfoJSON (0.00s)297 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)298 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)299 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)300 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)301 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)302=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)303=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon305=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI306=== CONT TestConvertHashToNix32/SRI_format_to_Nix32307=== CONT TestConvertHashToNix32/already_Nix32_format308=== CONT TestConvertHashToNix32/invalid_format309--- PASS: TestPathInfoHashCompatibility (0.00s)310 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)311 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)313 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)314=== CONT TestEncodeNixBase32/test_string_hash315=== CONT TestEncodeNixBase32/empty_input316=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error317=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error318=== CONT TestGetStorePathHash/basename_without_hyphen_should_error319=== CONT TestPathInfoCACompatibility/null_ca_field320--- PASS: TestConvertHashToNix32 (0.00s)321 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)322 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)323 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)324=== CONT TestGetStorePathHash/valid_store_path325=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method326--- PASS: TestEncodeNixBase32 (0.00s)327 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)328 --- PASS: TestEncodeNixBase32/empty_input (0.00s)329--- PASS: TestGetStorePathHash (0.00s)330 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)331 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)332 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)333 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)334=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive335=== CONT TestPathInfoCACompatibility/new_structured_format_-_text336=== CONT TestUploadMultipart_SupersededByPeer/exists337=== CONT TestPathInfoCACompatibility/old_string_format_-_text338--- PASS: TestPathInfoCACompatibility (0.00s)339 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)342 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)343 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)344=== CONT TestUploadMultipart_SupersededByPeer/missing345=== CONT TestPartSizeForNAR/zero_stays_at_minimum346=== CONT TestPartSizeForNAR/1_TiB347=== CONT TestPartSizeForNAR/capped_at_5_GiB348=== CONT TestPartSizeForNAR/5_TiB_S3_max_object349=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum350=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts351=== CONT TestPartSizeForNAR/small_stays_at_minimum352--- PASS: TestPartSizeForNAR (0.00s)353 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)354 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)355 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)356 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)357 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)358 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)359 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)360=== CONT TestFilterOversizedClosures/all_closures_skipped361--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)362 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)363 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)364=== CONT TestFilterOversizedClosures/no_limit_keeps_everything365=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3662026/09/22 11:04:15 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50367=== CONT TestSetClientTLSErrors/missing_cert_file3682026/09/22 11:04:15 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=2000369--- PASS: TestFilterOversizedClosures (0.00s)370 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)371 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)372 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)373=== CONT TestSetClientTLSErrors/invalid_ca_file374=== CONT TestSetClientTLSErrors/missing_ca_file375=== CONT TestSetClientTLSErrors/missing_key_file376--- PASS: TestDumpPathWriterError (0.04s)377--- PASS: TestSetClientTLSErrors (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)381 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3822026/09/22 11:04:15 http: TLS handshake error from 127.0.0.1:62923: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.01s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.05s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".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-94358-4077451566/postgres1966920368/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-94358-4077451566/postgres1966920368/data -l logfile start421422/nix/var/nix/builds/nix-94358-4077451566/postgres1966920368:5432 - no response4232026-09-22 11:04:16.984 UTC [94395] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-22 11:04:16.984 UTC [94395] LOG: listening on Unix socket "/nix/var/nix/builds/nix-94358-4077451566/postgres1966920368/.s.PGSQL.5432"4252026-09-22 11:04:16.986 UTC [94402] LOG: database system was shut down at 2026-09-22 11:04:16 UTC4262026-09-22 11:04:16.987 UTC [94395] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-94358-4077451566/postgres1966920368:5432 - accepting connections428{"timestamp":"2026-09-22T11:04:17.201316Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"36a4788a-f3e3-46b4-b82d-0ec7e9914a67","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestResolveDBConnectionString462=== PAUSE TestResolveDBConnectionString463=== RUN TestLeadElectsOneAndHandsOver464=== PAUSE TestLeadElectsOneAndHandsOver465=== RUN TestLeadIncumbentWinsAfterRestart4662026-09-22 11:04:17.426 UTC [94432] ERROR: relation "goose_db_version" does not exist at character 364672026-09-22 11:04:17.426 UTC [94432] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4682026/09/22 11:04:17 OK 20241026095416_initial_model.sql (3.79ms)4692026/09/22 11:04:17 OK 20251210153512_drop_unused_gin_index.sql (458.04µs)4702026/09/22 11:04:17 OK 20251218171726_add_pins.sql (945.04µs)4712026/09/22 11:04:17 OK 20260628120000_add_object_size_and_stats.sql (933.17µs)4722026/09/22 11:04:17 OK 20260905000000_add_claims.sql (1.11ms)4732026/09/22 11:04:17 OK 20260920000000_drop_claims.sql (668.63µs)4742026/09/22 11:04:17 goose: successfully migrated database to version: 202609200000004752026/09/22 11:04:17 OK 1_commit_pending_closure.sql (909.25µs)4762026/09/22 11:04:17 OK 2_object_stats_trigger.sql (218.79µs)4772026/09/22 11:04:17 goose: up to current file version: 24782026/09/22 11:04:17 INFO lead: acquired remote=192.0.2.1:12344792026/09/22 11:04:18 INFO lead: released remote=192.0.2.1:12344802026/09/22 11:04:18 INFO lead: acquired remote=192.0.2.1:12344812026/09/22 11:04:18 INFO lead: released remote=192.0.2.1:1234482--- PASS: TestLeadIncumbentWinsAfterRestart (0.84s)483=== RUN TestLeadEndsOnShutdown484=== PAUSE TestLeadEndsOnShutdown485=== RUN TestGCAdvisoryLockBlocksConcurrentRun4862026-09-22 11:04:18.227 UTC [94436] ERROR: relation "goose_db_version" does not exist at character 364872026-09-22 11:04:18.227 UTC [94436] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4882026/09/22 11:04:18 OK 20241026095416_initial_model.sql (3.91ms)4892026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (546.33µs)4902026/09/22 11:04:18 OK 20251218171726_add_pins.sql (899µs)4912026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (939.08µs)4922026/09/22 11:04:18 OK 20260905000000_add_claims.sql (1.08ms)4932026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (678.17µs)4942026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000004952026/09/22 11:04:18 OK 1_commit_pending_closure.sql (909.79µs)4962026/09/22 11:04:18 OK 2_object_stats_trigger.sql (225.33µs)4972026/09/22 11:04:18 goose: up to current file version: 2498--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)499=== RUN TestGCBugBareHashReferences500=== PAUSE TestGCBugBareHashReferences501=== RUN TestGCMetrics502=== PAUSE TestGCMetrics503=== RUN TestGCTaskStore_StartNew504=== PAUSE TestGCTaskStore_StartNew505=== RUN TestGCTaskStore_DeduplicateSameParams506=== PAUSE TestGCTaskStore_DeduplicateSameParams507=== RUN TestGCTaskStore_ConflictDifferentParams508=== PAUSE TestGCTaskStore_ConflictDifferentParams509=== RUN TestGCTaskStore_GetEmpty510=== PAUSE TestGCTaskStore_GetEmpty511=== RUN TestGCTaskStore_GetReturnsLatest512=== PAUSE TestGCTaskStore_GetReturnsLatest513=== RUN TestGCTaskStore_CompletedAllowsNewTask514=== PAUSE TestGCTaskStore_CompletedAllowsNewTask515=== RUN TestGCTaskStore_PhaseUpdates516=== PAUSE TestGCTaskStore_PhaseUpdates517=== RUN TestGCTaskStore_Fail518=== PAUSE TestGCTaskStore_Fail519=== RUN TestGracefulShutdownDrainsInflight520=== PAUSE TestGracefulShutdownDrainsInflight521=== RUN TestService_healthCheckHandler522=== PAUSE TestService_healthCheckHandler523=== RUN TestService_readinessHandler524=== PAUSE TestService_readinessHandler525=== RUN TestGenerateLandingPage526=== PAUSE TestGenerateLandingPage527=== RUN TestCacheConfigHandlerMaxNarSize528=== PAUSE TestCacheConfigHandlerMaxNarSize529=== RUN TestCreatePendingClosureRejectsOversizedNAR530=== PAUSE TestCreatePendingClosureRejectsOversizedNAR531=== RUN TestNARDeduplicationMetadataUploadBug532=== PAUSE TestNARDeduplicationMetadataUploadBug533=== RUN TestMetricsInventory534=== PAUSE TestMetricsInventory535=== RUN TestService_NativeMTLS536=== PAUSE TestService_NativeMTLS537=== RUN TestServerTLSConfig538=== PAUSE TestServerTLSConfig539=== RUN TestMultipartCleanup540=== PAUSE TestMultipartCleanup541=== RUN TestObjectStatsTrigger542=== PAUSE TestObjectStatsTrigger543=== RUN TestOrphanedObjectsGC544=== PAUSE TestOrphanedObjectsGC545=== RUN TestOrphanedObjectsGCStressTest546=== PAUSE TestOrphanedObjectsGCStressTest547=== RUN TestResurrectedObjectNotDeleted548=== PAUSE TestResurrectedObjectNotDeleted549=== RUN TestCreatePin_ReservedPins550=== PAUSE TestCreatePin_ReservedPins551=== RUN TestParseSingleRange552=== PAUSE TestParseSingleRange553=== RUN TestIsValidCachePath554=== PAUSE TestIsValidCachePath555=== RUN TestReadProxyNarinfo556=== PAUSE TestReadProxyNarinfo557=== RUN TestReadProxyNarinfoAlreadyDecompressed558=== PAUSE TestReadProxyNarinfoAlreadyDecompressed559=== RUN TestReadProxyNarStreaming560=== PAUSE TestReadProxyNarStreaming561=== RUN TestReadProxy404562=== PAUSE TestReadProxy404563=== RUN TestReadProxyInvalidPath564=== PAUSE TestReadProxyInvalidPath565=== RUN TestReadProxyHead566=== PAUSE TestReadProxyHead567=== RUN TestReadProxyConditionalGet568=== PAUSE TestReadProxyConditionalGet569=== RUN TestReadProxyRootRedirectsToIndexHTML570=== PAUSE TestReadProxyRootRedirectsToIndexHTML571=== RUN TestReadProxyDisabled572=== PAUSE TestReadProxyDisabled573=== RUN TestReadRedirectNar574=== PAUSE TestReadRedirectNar575=== RUN TestReadRedirectKeepsNarinfoProxied576=== PAUSE TestReadRedirectKeepsNarinfoProxied577=== RUN TestReadProxyRangeRequest578=== PAUSE TestReadProxyRangeRequest579=== RUN TestReadRedirectUsesPublicS3URL580=== PAUSE TestReadRedirectUsesPublicS3URL581=== RUN TestRedundantMultipartUpload582=== PAUSE TestRedundantMultipartUpload583=== RUN TestCompleteMultipartUpload_ErrorButObjectExists584=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists585=== RUN TestCompletedNarNotReofferedAcrossClosures586=== PAUSE TestCompletedNarNotReofferedAcrossClosures587=== RUN TestPresignedUploadRegisteredBeforeCommit588=== PAUSE TestPresignedUploadRegisteredBeforeCommit589=== RUN TestService_Rustfstest590=== PAUSE TestService_Rustfstest591=== RUN TestParseSize592=== PAUSE TestParseSize593=== RUN TestSkippedUploadsHandler594=== PAUSE TestSkippedUploadsHandler595=== RUN TestSystemdListenerNotActivated596--- PASS: TestSystemdListenerNotActivated (0.00s)597=== RUN TestWatchdogBeatsWhenHealthy598--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)599=== RUN TestWatchdogSkipsWhenUnhealthy6002026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6012026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6022026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6032026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6042026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6052026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6062026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6072026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6082026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6092026/09/22 11:04:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"610--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)611=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle612=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle613=== RUN TestProxyWriteTimeout614=== PAUSE TestProxyWriteTimeout615=== RUN TestIsValidUploadKey616=== PAUSE TestIsValidUploadKey617=== RUN TestUploadHandlersRejectInvalidKeys618=== PAUSE TestUploadHandlersRejectInvalidKeys619=== RUN TestUploadHandlersRejectOversizedBody620=== PAUSE TestUploadHandlersRejectOversizedBody621=== RUN TestService_cleanupPendingClosuresHandler622=== PAUSE TestService_cleanupPendingClosuresHandler623=== RUN TestService_createPendingClosureHandler624=== PAUSE TestService_createPendingClosureHandler625=== RUN TestService_verifyS3Integrity626=== PAUSE TestService_verifyS3Integrity627=== RUN TestCompleteMultipartUnregistered628=== PAUSE TestCompleteMultipartUnregistered629=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT630=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT631=== CONT TestService_AuthMiddleware632=== CONT TestMultipartCleanup633=== CONT TestReadProxyRangeRequest634=== CONT TestProxyWriteTimeout635=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT636=== RUN TestProxyWriteTimeout/narinfo637=== CONT TestReadRedirectKeepsNarinfoProxied638=== CONT TestRedundantMultipartUpload639=== PAUSE TestProxyWriteTimeout/narinfo640=== RUN TestProxyWriteTimeout/1_GiB_nar641=== PAUSE TestProxyWriteTimeout/1_GiB_nar642=== RUN TestProxyWriteTimeout/10_GiB_nar643=== PAUSE TestProxyWriteTimeout/10_GiB_nar644=== RUN TestProxyWriteTimeout/unknown_size645=== PAUSE TestProxyWriteTimeout/unknown_size646=== CONT TestService_createPendingClosureHandler647=== CONT TestReadRedirectNar648=== CONT TestReadProxyDisabled649=== CONT TestPresignedUploadRegisteredBeforeCommit6502026-09-22 11:04:18.895 UTC [94459] ERROR: relation "goose_db_version" does not exist at character 366512026-09-22 11:04:18.895 UTC [94459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026-09-22 11:04:18.896 UTC [94458] ERROR: relation "goose_db_version" does not exist at character 366532026-09-22 11:04:18.896 UTC [94458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6542026-09-22 11:04:18.902 UTC [94460] ERROR: relation "goose_db_version" does not exist at character 366552026-09-22 11:04:18.902 UTC [94460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6562026-09-22 11:04:18.905 UTC [94461] ERROR: relation "goose_db_version" does not exist at character 366572026-09-22 11:04:18.905 UTC [94461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6582026-09-22 11:04:18.906 UTC [94462] ERROR: relation "goose_db_version" does not exist at character 366592026-09-22 11:04:18.906 UTC [94462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6602026-09-22 11:04:18.908 UTC [94464] ERROR: relation "goose_db_version" does not exist at character 366612026-09-22 11:04:18.908 UTC [94464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6622026-09-22 11:04:18.908 UTC [94463] ERROR: relation "goose_db_version" does not exist at character 366632026-09-22 11:04:18.908 UTC [94463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6642026/09/22 11:04:18 OK 20241026095416_initial_model.sql (7.79ms)6652026-09-22 11:04:18.910 UTC [94466] ERROR: relation "goose_db_version" does not exist at character 366662026-09-22 11:04:18.910 UTC [94466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026-09-22 11:04:18.910 UTC [94467] ERROR: relation "goose_db_version" does not exist at character 366682026-09-22 11:04:18.910 UTC [94467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6692026-09-22 11:04:18.911 UTC [94465] ERROR: relation "goose_db_version" does not exist at character 366702026-09-22 11:04:18.911 UTC [94465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6712026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (851.17µs)6722026/09/22 11:04:18 OK 20251218171726_add_pins.sql (4.4ms)6732026/09/22 11:04:18 OK 20241026095416_initial_model.sql (13.41ms)6742026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (704µs)6752026/09/22 11:04:18 OK 20241026095416_initial_model.sql (9.88ms)6762026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (2.51ms)6772026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)6782026/09/22 11:04:18 OK 20251218171726_add_pins.sql (2.32ms)6792026/09/22 11:04:18 OK 20241026095416_initial_model.sql (9.81ms)6802026/09/22 11:04:18 OK 20260905000000_add_claims.sql (2.36ms)6812026/09/22 11:04:18 OK 20251218171726_add_pins.sql (2.36ms)6822026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.71ms)6832026/09/22 11:04:18 OK 20241026095416_initial_model.sql (10.82ms)6842026/09/22 11:04:18 OK 20241026095416_initial_model.sql (6.41ms)6852026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)6862026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (810.25µs)6872026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (746.92µs)6882026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (1.74ms)6892026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000006902026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.64ms)6912026/09/22 11:04:18 OK 20241026095416_initial_model.sql (7.87ms)6922026/09/22 11:04:18 OK 20251218171726_add_pins.sql (1.89ms)6932026/09/22 11:04:18 OK 20241026095416_initial_model.sql (6.36ms)6942026/09/22 11:04:18 OK 20260905000000_add_claims.sql (2.8ms)6952026/09/22 11:04:18 OK 20251218171726_add_pins.sql (1.69ms)6962026/09/22 11:04:18 OK 20251218171726_add_pins.sql (2.14ms)6972026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (445.71µs)6982026/09/22 11:04:18 OK 20241026095416_initial_model.sql (7.49ms)6992026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (960.17µs)7002026/09/22 11:04:18 OK 1_commit_pending_closure.sql (2.14ms)7012026/09/22 11:04:18 OK 20241026095416_initial_model.sql (7.28ms)7022026/09/22 11:04:18 OK 20260905000000_add_claims.sql (2.11ms)7032026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (696.92µs)7042026/09/22 11:04:18 OK 2_object_stats_trigger.sql (476.08µs)7052026/09/22 11:04:18 goose: up to current file version: 27062026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (1.14ms)7072026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007082026/09/22 11:04:18 OK 20251218171726_add_pins.sql (987.29µs)7092026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.88ms)7102026/09/22 11:04:18 OK 20251210153512_drop_unused_gin_index.sql (874.42µs)7112026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.54ms)7122026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (1.15ms)7132026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007142026/09/22 11:04:18 OK 20251218171726_add_pins.sql (1.62ms)7152026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.88ms)7162026/09/22 11:04:18 OK 20251218171726_add_pins.sql (1.18ms)7172026/09/22 11:04:18 OK 1_commit_pending_closure.sql (1.46ms)7182026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)7192026/09/22 11:04:18 OK 20251218171726_add_pins.sql (1.58ms)7202026/09/22 11:04:18 OK 1_commit_pending_closure.sql (1.31ms)7212026/09/22 11:04:18 OK 2_object_stats_trigger.sql (629.75µs)7222026/09/22 11:04:18 goose: up to current file version: 27232026/09/22 11:04:18 OK 20260905000000_add_claims.sql (1.44ms)7242026/09/22 11:04:18 OK 20260905000000_add_claims.sql (1.88ms)7252026/09/22 11:04:18 OK 2_object_stats_trigger.sql (359.04µs)7262026/09/22 11:04:18 goose: up to current file version: 27272026/09/22 11:04:18 OK 20260905000000_add_claims.sql (2.08ms)7282026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.61ms)7292026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (2.2ms)7302026/09/22 11:04:18 OK 20260628120000_add_object_size_and_stats.sql (1.12ms)7312026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (856.17µs)7322026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007332026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (1.01ms)7342026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007352026/09/22 11:04:18 OK 20260905000000_add_claims.sql (1.72ms)7362026/09/22 11:04:18 OK 1_commit_pending_closure.sql (785.13µs)7372026/09/22 11:04:18 OK 1_commit_pending_closure.sql (931.04µs)7382026/09/22 11:04:18 OK 2_object_stats_trigger.sql (182.67µs)7392026/09/22 11:04:18 goose: up to current file version: 27402026/09/22 11:04:18 OK 2_object_stats_trigger.sql (190.5µs)7412026/09/22 11:04:18 goose: up to current file version: 27422026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (4.13ms)7432026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007442026/09/22 11:04:18 OK 1_commit_pending_closure.sql (810.46µs)7452026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (3.93ms)7462026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007472026/09/22 11:04:18 OK 2_object_stats_trigger.sql (243.08µs)7482026/09/22 11:04:18 goose: up to current file version: 27492026/09/22 11:04:18 OK 20260905000000_add_claims.sql (4.87ms)7502026/09/22 11:04:18 OK 20260905000000_add_claims.sql (4.76ms)7512026/09/22 11:04:18 OK 20260905000000_add_claims.sql (5.25ms)7522026/09/22 11:04:18 OK 1_commit_pending_closure.sql (810.75µs)7532026/09/22 11:04:18 OK 2_object_stats_trigger.sql (172.17µs)7542026/09/22 11:04:18 goose: up to current file version: 27552026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (6.32ms)7562026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (6.42ms)7572026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007582026/09/22 11:04:18 OK 20260920000000_drop_claims.sql (6.36ms)7592026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007602026/09/22 11:04:18 goose: successfully migrated database to version: 202609200000007612026/09/22 11:04:18 OK 1_commit_pending_closure.sql (720.25µs)7622026/09/22 11:04:18 OK 1_commit_pending_closure.sql (752.04µs)7632026/09/22 11:04:18 OK 1_commit_pending_closure.sql (748.33µs)7642026/09/22 11:04:18 OK 2_object_stats_trigger.sql (167.58µs)7652026/09/22 11:04:18 goose: up to current file version: 27662026/09/22 11:04:18 OK 2_object_stats_trigger.sql (162.67µs)7672026/09/22 11:04:18 goose: up to current file version: 27682026/09/22 11:04:18 OK 2_object_stats_trigger.sql (184.88µs)7692026/09/22 11:04:18 goose: up to current file version: 27702026/09/22 11:04:18 INFO Received uploads request method=POST path=/api/pending_closures771--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)772=== CONT TestReadProxyRootRedirectsToIndexHTML7732026/09/22 11:04:19 INFO Received uploads request method=POST path=/api/pending_closures7742026/09/22 11:04:19 INFO Received uploads request method=POST path=/api/pending_closures7752026/09/22 11:04:19 INFO Received uploads request method=POST path=/api/pending_closures7762026/09/22 11:04:19 INFO Received uploads request method=POST path=/api/pending_closures7772026/09/22 11:04:19 INFO Received cleanup request method=DELETE path=/api/pending_closures7782026/09/22 11:04:19 INFO Aborted multipart uploads count=1779--- PASS: TestMultipartCleanup (0.95s)780=== CONT TestReadProxyConditionalGet781--- PASS: TestReadProxyDisabled (1.00s)782=== CONT TestReadProxyHead783--- PASS: TestReadRedirectKeepsNarinfoProxied (1.19s)784=== CONT TestReadProxyInvalidPath7852026/09/22 11:04:19 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"786--- PASS: TestService_AuthMiddleware (1.37s)787=== CONT TestReadProxy4047882026-09-22 11:04:19.940 UTC [94477] ERROR: relation "goose_db_version" does not exist at character 367892026-09-22 11:04:19.940 UTC [94477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7902026/09/22 11:04:20 OK 20241026095416_initial_model.sql (59.96ms)7912026/09/22 11:04:20 OK 20251210153512_drop_unused_gin_index.sql (13.16ms)7922026/09/22 11:04:20 OK 20251218171726_add_pins.sql (26.32ms)7932026/09/22 11:04:20 INFO Received uploads request method=POST path=/api/pending_closures7942026/09/22 11:04:20 OK 20260628120000_add_object_size_and_stats.sql (20.14ms)7952026/09/22 11:04:20 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7962026/09/22 11:04:20 INFO Received uploads request method=POST path=/api/pending_closures797--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.63s)798=== CONT TestReadProxyNarStreaming7992026/09/22 11:04:20 OK 20260905000000_add_claims.sql (61.35ms)8002026/09/22 11:04:20 OK 20260920000000_drop_claims.sql (42.36ms)8012026/09/22 11:04:20 goose: successfully migrated database to version: 202609200000008022026/09/22 11:04:20 OK 1_commit_pending_closure.sql (2.48ms)8032026/09/22 11:04:20 OK 2_object_stats_trigger.sql (565.38µs)8042026/09/22 11:04:20 goose: up to current file version: 28052026/09/22 11:04:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8062026/09/22 11:04:20 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjZiYWYzYjItMDRlYS00YmNkLWI4ZmUtOGM4MmIxZjYwMzYxLjhkMDI2OGZjLWIxMWEtNDAwNy05MDIzLWIxYTRmZjVhZmRjZHgxNzkwMDc1MDU5MTM5OTY2MDAw parts=108072026/09/22 11:04:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8082026/09/22 11:04:20 INFO Completed upload id=18092026/09/22 11:04:20 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008102026/09/22 11:04:20 INFO Received uploads request method=POST path=/api/pending_closures8112026/09/22 11:04:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures8122026/09/22 11:04:20 INFO Aborted multipart uploads count=08132026/09/22 11:04:20 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=0814--- PASS: TestReadRedirectNar (1.87s)815=== CONT TestReadProxyNarinfoAlreadyDecompressed8162026/09/22 11:04:20 INFO Vacuumed table table=pending_closures8172026/09/22 11:04:20 INFO Vacuumed table table=pending_objects8182026/09/22 11:04:20 INFO Vacuumed table table=multipart_uploads8192026/09/22 11:04:20 INFO Vacuumed table table=closures8202026/09/22 11:04:20 INFO Vacuumed table table=objects8212026/09/22 11:04:20 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000822--- PASS: TestService_createPendingClosureHandler (1.95s)823=== CONT TestReadProxyNarinfo8242026-09-22 11:04:20.473 UTC [94484] ERROR: relation "goose_db_version" does not exist at character 368252026-09-22 11:04:20.473 UTC [94484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026-09-22 11:04:20.475 UTC [94485] ERROR: relation "goose_db_version" does not exist at character 368272026-09-22 11:04:20.475 UTC [94485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC828--- PASS: TestReadProxyRangeRequest (2.05s)829=== CONT TestIsValidCachePath830=== RUN TestIsValidCachePath/narinfo831=== PAUSE TestIsValidCachePath/narinfo832=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars833=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars834=== RUN TestIsValidCachePath/nar_zst835=== PAUSE TestIsValidCachePath/nar_zst836=== RUN TestIsValidCachePath/nar_xz837=== PAUSE TestIsValidCachePath/nar_xz838=== RUN TestIsValidCachePath/nar_bz2839=== PAUSE TestIsValidCachePath/nar_bz2840=== RUN TestIsValidCachePath/nar_uncompressed841=== PAUSE TestIsValidCachePath/nar_uncompressed842=== RUN TestIsValidCachePath/ls843=== PAUSE TestIsValidCachePath/ls844=== RUN TestIsValidCachePath/log845=== PAUSE TestIsValidCachePath/log846=== RUN TestIsValidCachePath/realisation847=== PAUSE TestIsValidCachePath/realisation848=== RUN TestIsValidCachePath/nix-cache-info849=== PAUSE TestIsValidCachePath/nix-cache-info850=== RUN TestIsValidCachePath/index.html851=== PAUSE TestIsValidCachePath/index.html852=== RUN TestIsValidCachePath/traversal_parent853=== PAUSE TestIsValidCachePath/traversal_parent854=== RUN TestIsValidCachePath/traversal_in_middle855=== PAUSE TestIsValidCachePath/traversal_in_middle856=== RUN TestIsValidCachePath/invalid_char_e857=== PAUSE TestIsValidCachePath/invalid_char_e858=== RUN TestIsValidCachePath/invalid_char_u859=== PAUSE TestIsValidCachePath/invalid_char_u860=== RUN TestIsValidCachePath/random_path861=== PAUSE TestIsValidCachePath/random_path862=== RUN TestIsValidCachePath/empty863=== PAUSE TestIsValidCachePath/empty864=== RUN TestIsValidCachePath/leading_slash865=== PAUSE TestIsValidCachePath/leading_slash866=== RUN TestIsValidCachePath/wrong_extension867=== PAUSE TestIsValidCachePath/wrong_extension868=== RUN TestIsValidCachePath/short_hash869=== PAUSE TestIsValidCachePath/short_hash870=== CONT TestParseSingleRange871=== RUN TestParseSingleRange/none872=== PAUSE TestParseSingleRange/none873=== RUN TestParseSingleRange/unknown_unit874=== PAUSE TestParseSingleRange/unknown_unit875=== RUN TestParseSingleRange/multi-range_ignored876=== PAUSE TestParseSingleRange/multi-range_ignored877=== RUN TestParseSingleRange/malformed_no_dash878=== PAUSE TestParseSingleRange/malformed_no_dash879=== RUN TestParseSingleRange/malformed_both_empty880=== PAUSE TestParseSingleRange/malformed_both_empty881=== RUN TestParseSingleRange/malformed_end_before_start882=== PAUSE TestParseSingleRange/malformed_end_before_start883=== RUN TestParseSingleRange/closed884=== PAUSE TestParseSingleRange/closed885=== RUN TestParseSingleRange/open-ended886=== PAUSE TestParseSingleRange/open-ended887=== RUN TestParseSingleRange/end_clamped_to_size888=== PAUSE TestParseSingleRange/end_clamped_to_size889=== RUN TestParseSingleRange/suffix890=== PAUSE TestParseSingleRange/suffix891=== RUN TestParseSingleRange/suffix_exceeds_size892=== PAUSE TestParseSingleRange/suffix_exceeds_size893=== RUN TestParseSingleRange/single_byte894=== PAUSE TestParseSingleRange/single_byte895=== RUN TestParseSingleRange/start_past_EOF896=== PAUSE TestParseSingleRange/start_past_EOF897=== RUN TestParseSingleRange/start_far_past_EOF898=== PAUSE TestParseSingleRange/start_far_past_EOF899=== CONT TestCreatePin_ReservedPins9002026/09/22 11:04:20 OK 20241026095416_initial_model.sql (125.46ms)9012026/09/22 11:04:20 OK 20241026095416_initial_model.sql (118.58ms)9022026/09/22 11:04:20 OK 20251210153512_drop_unused_gin_index.sql (5.07ms)9032026/09/22 11:04:20 OK 20251210153512_drop_unused_gin_index.sql (833.04µs)9042026/09/22 11:04:20 OK 20251218171726_add_pins.sql (1.83ms)9052026/09/22 11:04:20 OK 20251218171726_add_pins.sql (12.84ms)9062026/09/22 11:04:20 OK 20260628120000_add_object_size_and_stats.sql (16.12ms)9072026-09-22 11:04:20.664 UTC [94488] ERROR: relation "goose_db_version" does not exist at character 369082026-09-22 11:04:20.664 UTC [94488] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026/09/22 11:04:20 OK 20260628120000_add_object_size_and_stats.sql (11.92ms)9102026/09/22 11:04:20 OK 20260905000000_add_claims.sql (7.09ms)9112026/09/22 11:04:20 OK 20260920000000_drop_claims.sql (9.44ms)9122026/09/22 11:04:20 goose: successfully migrated database to version: 202609200000009132026/09/22 11:04:20 OK 1_commit_pending_closure.sql (1.1ms)9142026/09/22 11:04:20 OK 2_object_stats_trigger.sql (217.58µs)9152026/09/22 11:04:20 goose: up to current file version: 29162026/09/22 11:04:20 OK 20260905000000_add_claims.sql (19.95ms)9172026/09/22 11:04:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62966/oidc9182026/09/22 11:04:20 OK 20260920000000_drop_claims.sql (10.13ms)9192026/09/22 11:04:20 goose: successfully migrated database to version: 202609200000009202026/09/22 11:04:20 OK 1_commit_pending_closure.sql (1.21ms)9212026/09/22 11:04:20 OK 2_object_stats_trigger.sql (219.63µs)9222026/09/22 11:04:20 goose: up to current file version: 29232026/09/22 11:04:20 INFO Received uploads request method=POST path=/api/pending_closures9242026/09/22 11:04:20 OK 20241026095416_initial_model.sql (71ms)9252026/09/22 11:04:20 OK 20251210153512_drop_unused_gin_index.sql (6.91ms)9262026/09/22 11:04:20 INFO Received uploads request method=POST path=/api/pending_closures9272026/09/22 11:04:20 OK 20251218171726_add_pins.sql (19.42ms)9282026/09/22 11:04:20 OK 20260628120000_add_object_size_and_stats.sql (12.52ms)9292026/09/22 11:04:20 OK 20260905000000_add_claims.sql (29.12ms)9302026/09/22 11:04:20 OK 20260920000000_drop_claims.sql (31.5ms)9312026/09/22 11:04:20 goose: successfully migrated database to version: 202609200000009322026/09/22 11:04:20 OK 1_commit_pending_closure.sql (1.93ms)9332026/09/22 11:04:20 OK 2_object_stats_trigger.sql (290.38µs)9342026/09/22 11:04:20 goose: up to current file version: 2935--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.88s)936=== CONT TestResurrectedObjectNotDeleted9372026-09-22 11:04:21.093 UTC [94493] ERROR: relation "goose_db_version" does not exist at character 369382026-09-22 11:04:21.093 UTC [94493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC939--- PASS: TestReadProxyConditionalGet (1.64s)940=== CONT TestOrphanedObjectsGCStressTest9412026/09/22 11:04:21 OK 20241026095416_initial_model.sql (112.03ms)9422026/09/22 11:04:21 OK 20251210153512_drop_unused_gin_index.sql (8.53ms)9432026/09/22 11:04:21 OK 20251218171726_add_pins.sql (27.84ms)944--- PASS: TestReadProxyHead (1.83s)945=== CONT TestReadRedirectUsesPublicS3URL9462026/09/22 11:04:21 OK 20260628120000_add_object_size_and_stats.sql (35.78ms)9472026/09/22 11:04:21 OK 20260905000000_add_claims.sql (59.33ms)9482026/09/22 11:04:21 OK 20260920000000_drop_claims.sql (14.42ms)9492026/09/22 11:04:21 goose: successfully migrated database to version: 202609200000009502026/09/22 11:04:21 OK 1_commit_pending_closure.sql (2.1ms)9512026/09/22 11:04:21 OK 2_object_stats_trigger.sql (466.88µs)9522026/09/22 11:04:21 goose: up to current file version: 2953--- PASS: TestReadProxyInvalidPath (1.90s)954=== CONT TestOrphanedObjectsGC9552026-09-22 11:04:21.735 UTC [94500] ERROR: relation "goose_db_version" does not exist at character 369562026-09-22 11:04:21.735 UTC [94500] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9572026-09-22 11:04:21.815 UTC [94501] ERROR: relation "goose_db_version" does not exist at character 369582026-09-22 11:04:21.815 UTC [94501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC959--- PASS: TestReadProxy404 (1.95s)960=== CONT TestObjectStatsTrigger9612026-09-22 11:04:21.892 UTC [94504] ERROR: relation "goose_db_version" does not exist at character 369622026-09-22 11:04:21.892 UTC [94504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9632026/09/22 11:04:21 OK 20241026095416_initial_model.sql (111.96ms)9642026/09/22 11:04:21 OK 20251210153512_drop_unused_gin_index.sql (671.42µs)9652026/09/22 11:04:21 OK 20251218171726_add_pins.sql (1.32ms)9662026/09/22 11:04:21 OK 20260628120000_add_object_size_and_stats.sql (28.31ms)9672026-09-22 11:04:21.939 UTC [94506] ERROR: relation "goose_db_version" does not exist at character 369682026-09-22 11:04:21.939 UTC [94506] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9692026/09/22 11:04:21 OK 20260905000000_add_claims.sql (30.62ms)9702026/09/22 11:04:21 OK 20241026095416_initial_model.sql (91.06ms)9712026/09/22 11:04:21 OK 20251210153512_drop_unused_gin_index.sql (817.58µs)9722026/09/22 11:04:21 OK 20260920000000_drop_claims.sql (1.61ms)9732026/09/22 11:04:21 goose: successfully migrated database to version: 202609200000009742026/09/22 11:04:21 OK 20251218171726_add_pins.sql (1.59ms)9752026/09/22 11:04:21 OK 1_commit_pending_closure.sql (1.78ms)9762026/09/22 11:04:21 OK 2_object_stats_trigger.sql (399.42µs)9772026/09/22 11:04:21 goose: up to current file version: 29782026/09/22 11:04:21 OK 20241026095416_initial_model.sql (28.57ms)9792026/09/22 11:04:21 OK 20251210153512_drop_unused_gin_index.sql (638.25µs)9802026/09/22 11:04:21 OK 20251218171726_add_pins.sql (1.34ms)9812026/09/22 11:04:21 OK 20260628120000_add_object_size_and_stats.sql (16.58ms)9822026/09/22 11:04:21 OK 20260628120000_add_object_size_and_stats.sql (28.51ms)9832026/09/22 11:04:22 OK 20260905000000_add_claims.sql (34.23ms)9842026/09/22 11:04:22 OK 20260905000000_add_claims.sql (47.16ms)9852026/09/22 11:04:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9862026/09/22 11:04:22 OK 20260920000000_drop_claims.sql (38.6ms)9872026/09/22 11:04:22 goose: successfully migrated database to version: 202609200000009882026/09/22 11:04:22 OK 20260920000000_drop_claims.sql (17.87ms)9892026/09/22 11:04:22 goose: successfully migrated database to version: 202609200000009902026/09/22 11:04:22 OK 20241026095416_initial_model.sql (97.35ms)9912026/09/22 11:04:22 OK 1_commit_pending_closure.sql (2.57ms)9922026/09/22 11:04:22 OK 1_commit_pending_closure.sql (3.21ms)9932026/09/22 11:04:22 OK 2_object_stats_trigger.sql (642.25µs)9942026/09/22 11:04:22 goose: up to current file version: 29952026/09/22 11:04:22 OK 2_object_stats_trigger.sql (580.79µs)9962026/09/22 11:04:22 goose: up to current file version: 29972026/09/22 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (24.84ms)9982026/09/22 11:04:22 OK 20251218171726_add_pins.sql (14.52ms)9992026/09/22 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (32.83ms)10002026/09/22 11:04:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjZiYWYzYjItMDRlYS00YmNkLWI4ZmUtOGM4MmIxZjYwMzYxLjUyNzg4MzJkLWRkMzAtNDBmNS05ZTMxLTdhMmEyMmZiMmIwMHgxNzkwMDc1MDYwNzQyODA4MDAw parts=121001--- PASS: TestRedundantMultipartUpload (3.61s)1002=== CONT TestCompleteMultipartUnregistered10032026/09/22 11:04:22 OK 20260905000000_add_claims.sql (46.53ms)10042026/09/22 11:04:22 OK 20260920000000_drop_claims.sql (28.35ms)10052026/09/22 11:04:22 goose: successfully migrated database to version: 2026092000000010062026/09/22 11:04:22 OK 1_commit_pending_closure.sql (2.89ms)10072026/09/22 11:04:22 OK 2_object_stats_trigger.sql (638.79µs)10082026/09/22 11:04:22 goose: up to current file version: 21009--- PASS: TestReadProxyNarStreaming (2.05s)1010=== CONT TestService_verifyS3Integrity1011--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.03s)1012=== CONT TestGCMetrics10132026-09-22 11:04:22.497 UTC [94513] ERROR: relation "goose_db_version" does not exist at character 3610142026-09-22 11:04:22.497 UTC [94513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1015--- PASS: TestReadProxyNarinfo (2.17s)1016=== CONT TestClientErrorHandling1017=== RUN TestClientErrorHandling/InvalidStorePath1018=== PAUSE TestClientErrorHandling/InvalidStorePath1019=== RUN TestClientErrorHandling/InvalidAuthToken1020=== PAUSE TestClientErrorHandling/InvalidAuthToken1021=== RUN TestClientErrorHandling/ServerNotAvailable1022=== PAUSE TestClientErrorHandling/ServerNotAvailable1023=== CONT TestServerTLSConfig1024=== RUN TestServerTLSConfig/no_client_CA1025=== PAUSE TestServerTLSConfig/no_client_CA1026=== RUN TestServerTLSConfig/missing_CA_file1027=== PAUSE TestServerTLSConfig/missing_CA_file1028=== RUN TestServerTLSConfig/not_a_PEM_file1029=== PAUSE TestServerTLSConfig/not_a_PEM_file1030=== CONT TestProxyWriteTimeout/narinfo1031=== CONT TestGCBugBareHashReferences10322026-09-22 11:04:22.682 UTC [94514] ERROR: relation "goose_db_version" does not exist at character 3610332026-09-22 11:04:22.682 UTC [94514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10342026/09/22 11:04:22 OK 20241026095416_initial_model.sql (175.14ms)10352026/09/22 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (11.54ms)10362026/09/22 11:04:22 OK 20251218171726_add_pins.sql (17.58ms)10372026/09/22 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (29.03ms)10382026/09/22 11:04:22 OK 20260905000000_add_claims.sql (15.71ms)10392026/09/22 11:04:22 OK 20260920000000_drop_claims.sql (22.74ms)10402026/09/22 11:04:22 goose: successfully migrated database to version: 2026092000000010412026/09/22 11:04:22 OK 1_commit_pending_closure.sql (4.01ms)10422026/09/22 11:04:22 OK 2_object_stats_trigger.sql (1.28ms)10432026/09/22 11:04:22 goose: up to current file version: 210442026-09-22 11:04:22.820 UTC [94517] ERROR: relation "goose_db_version" does not exist at character 3610452026-09-22 11:04:22.820 UTC [94517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10462026/09/22 11:04:22 OK 20241026095416_initial_model.sql (97.65ms)10472026/09/22 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (12.98ms)10482026/09/22 11:04:22 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10492026/09/22 11:04:22 WARN Refused reserved pin name=worker-x86_64-linux10502026/09/22 11:04:22 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10512026/09/22 11:04:22 INFO Received create pin request method=POST path=/api/pins/my-app10522026/09/22 11:04:22 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1053--- PASS: TestCreatePin_ReservedPins (2.30s)1054=== CONT TestService_NativeMTLS10552026/09/22 11:04:22 OK 20251218171726_add_pins.sql (24.07ms)10562026/09/22 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (32.01ms)10572026/09/22 11:04:22 OK 20260905000000_add_claims.sql (12.16ms)10582026/09/22 11:04:22 OK 20260920000000_drop_claims.sql (16.06ms)10592026/09/22 11:04:22 goose: successfully migrated database to version: 2026092000000010602026/09/22 11:04:22 OK 1_commit_pending_closure.sql (2.62ms)10612026/09/22 11:04:22 OK 2_object_stats_trigger.sql (464.75µs)10622026/09/22 11:04:22 goose: up to current file version: 210632026/09/22 11:04:22 OK 20241026095416_initial_model.sql (94.85ms)10642026/09/22 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)10652026-09-22 11:04:22.985 UTC [94520] ERROR: relation "goose_db_version" does not exist at character 3610662026-09-22 11:04:22.985 UTC [94520] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10672026/09/22 11:04:22 OK 20251218171726_add_pins.sql (14.12ms)10682026/09/22 11:04:23 OK 20260628120000_add_object_size_and_stats.sql (27.65ms)10692026/09/22 11:04:23 OK 20260905000000_add_claims.sql (31.52ms)10702026/09/22 11:04:23 OK 20260920000000_drop_claims.sql (15.01ms)10712026/09/22 11:04:23 goose: successfully migrated database to version: 2026092000000010722026/09/22 11:04:23 OK 1_commit_pending_closure.sql (6.27ms)10732026/09/22 11:04:23 OK 2_object_stats_trigger.sql (804µs)10742026/09/22 11:04:23 goose: up to current file version: 210752026/09/22 11:04:23 OK 20241026095416_initial_model.sql (145.71ms)10762026/09/22 11:04:23 OK 20251210153512_drop_unused_gin_index.sql (4.55ms)1077--- PASS: TestResurrectedObjectNotDeleted (2.28s)1078=== CONT TestService_cleanupPendingClosuresHandler10792026/09/22 11:04:23 OK 20251218171726_add_pins.sql (33.23ms)10802026/09/22 11:04:23 OK 20260628120000_add_object_size_and_stats.sql (32.42ms)10812026-09-22 11:04:23.252 UTC [94523] ERROR: relation "goose_db_version" does not exist at character 3610822026-09-22 11:04:23.252 UTC [94523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10832026/09/22 11:04:23 OK 20260905000000_add_claims.sql (42.82ms)10842026/09/22 11:04:23 OK 20260920000000_drop_claims.sql (24.25ms)10852026/09/22 11:04:23 goose: successfully migrated database to version: 2026092000000010862026/09/22 11:04:23 OK 1_commit_pending_closure.sql (3.45ms)10872026/09/22 11:04:23 OK 2_object_stats_trigger.sql (1.26ms)10882026/09/22 11:04:23 goose: up to current file version: 210892026/09/22 11:04:23 OK 20241026095416_initial_model.sql (228.9ms)10902026/09/22 11:04:23 OK 20251210153512_drop_unused_gin_index.sql (9.96ms)10912026/09/22 11:04:23 OK 20251218171726_add_pins.sql (27.59ms)10922026/09/22 11:04:23 OK 20260628120000_add_object_size_and_stats.sql (50.06ms)10932026/09/22 11:04:23 OK 20260905000000_add_claims.sql (63.18ms)10942026-09-22 11:04:23.692 UTC [94526] ERROR: relation "goose_db_version" does not exist at character 3610952026-09-22 11:04:23.692 UTC [94526] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1096--- PASS: TestReadRedirectUsesPublicS3URL (2.35s)1097=== CONT TestLeadEndsOnShutdown10982026/09/22 11:04:23 OK 20260920000000_drop_claims.sql (54.65ms)10992026/09/22 11:04:23 goose: successfully migrated database to version: 2026092000000011002026/09/22 11:04:23 OK 1_commit_pending_closure.sql (3.48ms)11012026/09/22 11:04:23 OK 2_object_stats_trigger.sql (774.96µs)11022026/09/22 11:04:23 goose: up to current file version: 211032026-09-22 11:04:23.784 UTC [94529] ERROR: relation "goose_db_version" does not exist at character 3611042026-09-22 11:04:23.784 UTC [94529] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/09/22 11:04:23 OK 20241026095416_initial_model.sql (74.47ms)11062026/09/22 11:04:23 OK 20251210153512_drop_unused_gin_index.sql (9.77ms)11072026/09/22 11:04:23 OK 20251218171726_add_pins.sql (27.04ms)11082026/09/22 11:04:23 OK 20260628120000_add_object_size_and_stats.sql (27.34ms)11092026/09/22 11:04:23 OK 20260905000000_add_claims.sql (42.1ms)11102026/09/22 11:04:23 OK 20241026095416_initial_model.sql (143.57ms)11112026/09/22 11:04:23 OK 20251210153512_drop_unused_gin_index.sql (16.66ms)11122026/09/22 11:04:23 OK 20260920000000_drop_claims.sql (40.83ms)11132026/09/22 11:04:23 goose: successfully migrated database to version: 2026092000000011142026-09-22 11:04:23.978 UTC [94530] ERROR: relation "goose_db_version" does not exist at character 3611152026-09-22 11:04:23.978 UTC [94530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11162026/09/22 11:04:23 OK 1_commit_pending_closure.sql (8.64ms)11172026/09/22 11:04:23 OK 2_object_stats_trigger.sql (1.12ms)11182026/09/22 11:04:23 goose: up to current file version: 211192026/09/22 11:04:24 OK 20251218171726_add_pins.sql (31.75ms)11202026/09/22 11:04:24 OK 20260628120000_add_object_size_and_stats.sql (42.75ms)11212026/09/22 11:04:24 OK 20260905000000_add_claims.sql (54.46ms)11222026/09/22 11:04:24 OK 20260920000000_drop_claims.sql (47.25ms)11232026/09/22 11:04:24 goose: successfully migrated database to version: 2026092000000011242026/09/22 11:04:24 OK 1_commit_pending_closure.sql (4.83ms)11252026/09/22 11:04:24 OK 2_object_stats_trigger.sql (1.03ms)11262026/09/22 11:04:24 goose: up to current file version: 211272026/09/22 11:04:24 OK 20241026095416_initial_model.sql (210.27ms)11282026/09/22 11:04:24 OK 20251210153512_drop_unused_gin_index.sql (20.47ms)1129--- PASS: TestObjectStatsTrigger (2.45s)1130=== CONT TestUploadHandlersRejectOversizedBody11312026/09/22 11:04:24 OK 20251218171726_add_pins.sql (36.79ms)11322026/09/22 11:04:24 OK 20260628120000_add_object_size_and_stats.sql (26.54ms)1133=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1134=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1135=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1136=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1137=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1138=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1139=== CONT TestMetricsInventory11402026/09/22 11:04:24 OK 20260905000000_add_claims.sql (47.23ms)11412026/09/22 11:04:24 OK 20260920000000_drop_claims.sql (30.3ms)11422026/09/22 11:04:24 goose: successfully migrated database to version: 2026092000000011432026/09/22 11:04:24 OK 1_commit_pending_closure.sql (1.37ms)11442026/09/22 11:04:24 OK 2_object_stats_trigger.sql (339.88µs)11452026/09/22 11:04:24 goose: up to current file version: 211462026-09-22 11:04:24.449 UTC [94534] ERROR: relation "goose_db_version" does not exist at character 3611472026-09-22 11:04:24.449 UTC [94534] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026/09/22 11:04:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11492026/09/22 11:04:24 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1150--- PASS: TestCompleteMultipartUnregistered (2.38s)1151=== CONT TestLeadElectsOneAndHandsOver11522026-09-22 11:04:24.576 UTC [94537] ERROR: relation "goose_db_version" does not exist at character 3611532026-09-22 11:04:24.576 UTC [94537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11542026/09/22 11:04:24 OK 20241026095416_initial_model.sql (175.33ms)1155=== NAME TestOrphanedObjectsGC1156 orphaned_objects_gc_test.go:290: GC Test Summary:1157 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1158 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1159 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1160 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1161 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1162--- PASS: TestOrphanedObjectsGC (3.07s)1163=== CONT TestUploadHandlersRejectInvalidKeys1164=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1165=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1166=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1167=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1168=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1169=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1170=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1171=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1172=== CONT TestNARDeduplicationMetadataUploadBug11732026/09/22 11:04:24 OK 20251210153512_drop_unused_gin_index.sql (18.01ms)11742026/09/22 11:04:24 OK 20251218171726_add_pins.sql (44.08ms)11752026/09/22 11:04:24 OK 20260628120000_add_object_size_and_stats.sql (46.92ms)11762026/09/22 11:04:24 INFO Received uploads request method=POST path=/api/pending_closures11772026/09/22 11:04:24 OK 20260905000000_add_claims.sql (74.51ms)11782026/09/22 11:04:24 OK 20241026095416_initial_model.sql (267ms)11792026/09/22 11:04:24 OK 20260920000000_drop_claims.sql (77.26ms)11802026/09/22 11:04:24 goose: successfully migrated database to version: 2026092000000011812026/09/22 11:04:24 OK 1_commit_pending_closure.sql (4.18ms)11822026/09/22 11:04:24 OK 2_object_stats_trigger.sql (817.63µs)11832026/09/22 11:04:24 goose: up to current file version: 211842026/09/22 11:04:24 OK 20251210153512_drop_unused_gin_index.sql (14.68ms)11852026/09/22 11:04:24 OK 20251218171726_add_pins.sql (28.52ms)11862026/09/22 11:04:25 OK 20260628120000_add_object_size_and_stats.sql (47.23ms)11872026/09/22 11:04:25 OK 20260905000000_add_claims.sql (175.75ms)11882026/09/22 11:04:25 INFO Aborted multipart uploads count=011892026/09/22 11:04:25 WARN Force mode enabled - objects will be deleted immediately without grace period11902026/09/22 11:04:25 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=011912026/09/22 11:04:25 INFO Vacuumed table table=pending_closures11922026/09/22 11:04:25 INFO Vacuumed table table=pending_objects11932026/09/22 11:04:25 INFO Vacuumed table table=multipart_uploads11942026/09/22 11:04:25 INFO Vacuumed table table=closures11952026/09/22 11:04:25 INFO Vacuumed table table=objects1196--- PASS: TestGCMetrics (2.82s)1197=== CONT TestIsValidUploadKey1198=== RUN TestIsValidUploadKey/narinfo1199=== PAUSE TestIsValidUploadKey/narinfo1200=== RUN TestIsValidUploadKey/nar_zst1201=== PAUSE TestIsValidUploadKey/nar_zst1202=== RUN TestIsValidUploadKey/nar_xz1203=== PAUSE TestIsValidUploadKey/nar_xz1204=== RUN TestIsValidUploadKey/nar_plain1205=== PAUSE TestIsValidUploadKey/nar_plain1206=== RUN TestIsValidUploadKey/listing1207=== PAUSE TestIsValidUploadKey/listing1208=== RUN TestIsValidUploadKey/build_log1209=== PAUSE TestIsValidUploadKey/build_log1210=== RUN TestIsValidUploadKey/build_log_home-manager_file1211=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1212=== RUN TestIsValidUploadKey/build_log_plus_in_name1213=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1214=== RUN TestIsValidUploadKey/build_log_question_mark1215=== PAUSE TestIsValidUploadKey/build_log_question_mark1216=== RUN TestIsValidUploadKey/build_log_equals1217=== PAUSE TestIsValidUploadKey/build_log_equals1218=== RUN TestIsValidUploadKey/realisation1219=== PAUSE TestIsValidUploadKey/realisation1220=== RUN TestIsValidUploadKey/realisation_plus_in_output1221=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1222=== RUN TestIsValidUploadKey/nix-cache-info1223=== PAUSE TestIsValidUploadKey/nix-cache-info1224=== RUN TestIsValidUploadKey/index.html1225=== PAUSE TestIsValidUploadKey/index.html1226=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1227=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1228=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1229=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1230=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1231=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1232=== RUN TestIsValidUploadKey/traversal1233=== PAUSE TestIsValidUploadKey/traversal1234=== RUN TestIsValidUploadKey/traversal_nar1235=== PAUSE TestIsValidUploadKey/traversal_nar1236=== RUN TestIsValidUploadKey/absolute1237=== PAUSE TestIsValidUploadKey/absolute1238=== RUN TestIsValidUploadKey/empty_key1239=== PAUSE TestIsValidUploadKey/empty_key1240=== RUN TestIsValidUploadKey/unknown_type1241=== PAUSE TestIsValidUploadKey/unknown_type1242=== CONT TestResolveDBConnectionString1243=== RUN TestResolveDBConnectionString/flag_wins1244=== PAUSE TestResolveDBConnectionString/flag_wins1245=== RUN TestResolveDBConnectionString/file_when_flag_empty1246=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1247=== RUN TestResolveDBConnectionString/missing_file_is_an_error1248=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1249=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1250=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1251=== RUN TestResolveDBConnectionString/nothing_configured1252=== PAUSE TestResolveDBConnectionString/nothing_configured1253=== CONT TestCreatePendingClosureRejectsOversizedNAR12542026/09/22 11:04:25 INFO Received uploads request method=POST path=/api/pending_closures1255--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1256=== CONT TestPinProtectsFromGC12572026/09/22 11:04:25 OK 20260920000000_drop_claims.sql (60.68ms)12582026/09/22 11:04:25 goose: successfully migrated database to version: 2026092000000012592026/09/22 11:04:25 OK 1_commit_pending_closure.sql (3.4ms)12602026/09/22 11:04:25 OK 2_object_stats_trigger.sql (980.71µs)12612026/09/22 11:04:25 goose: up to current file version: 212622026-09-22 11:04:25.505 UTC [94543] ERROR: relation "goose_db_version" does not exist at character 3612632026-09-22 11:04:25.505 UTC [94543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12642026/09/22 11:04:25 OK 20241026095416_initial_model.sql (219.89ms)12652026/09/22 11:04:25 OK 20251210153512_drop_unused_gin_index.sql (11.5ms)1266--- PASS: TestGCBugBareHashReferences (3.19s)1267=== CONT TestCacheConfigHandlerMaxNarSize1268--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1269=== CONT TestGenerateLandingPage1270--- PASS: TestGenerateLandingPage (0.01s)1271=== CONT TestClientSharedPathCommittedMidPush12722026/09/22 11:04:25 OK 20251218171726_add_pins.sql (42.86ms)12732026/09/22 11:04:25 OK 20260628120000_add_object_size_and_stats.sql (48.44ms)12742026/09/22 11:04:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12752026/09/22 11:04:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1276--- PASS: TestService_NativeMTLS (3.06s)1277=== CONT TestService_readinessHandler12782026/09/22 11:04:25 OK 20260905000000_add_claims.sql (80.65ms)12792026/09/22 11:04:26 OK 20260920000000_drop_claims.sql (29.13ms)12802026/09/22 11:04:26 goose: successfully migrated database to version: 2026092000000012812026/09/22 11:04:26 OK 1_commit_pending_closure.sql (2.56ms)12822026/09/22 11:04:26 OK 2_object_stats_trigger.sql (503.17µs)12832026/09/22 11:04:26 goose: up to current file version: 212842026-09-22 11:04:26.284 UTC [94548] ERROR: relation "goose_db_version" does not exist at character 3612852026-09-22 11:04:26.284 UTC [94548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12862026/09/22 11:04:26 INFO Received cleanup request method=DELETE path=/api/pending_closures12872026/09/22 11:04:26 INFO Aborted multipart uploads count=012882026/09/22 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures12892026/09/22 11:04:26 INFO Received cleanup request method=DELETE path=/api/pending_closures12902026/09/22 11:04:26 INFO Aborted multipart uploads count=112912026/09/22 11:04:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12922026-09-22 11:04:26.462 UTC [94543] ERROR: Closure does not exist: id=112932026-09-22 11:04:26.462 UTC [94543] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12942026-09-22 11:04:26.462 UTC [94543] STATEMENT: -- name: CommitPendingClosure :exec1295 SELECT commit_pending_closure($1::bigint)1296 1297--- PASS: TestService_cleanupPendingClosuresHandler (3.27s)1298=== CONT TestService_healthCheckHandler12992026/09/22 11:04:26 OK 20241026095416_initial_model.sql (158.73ms)13002026/09/22 11:04:26 OK 20251210153512_drop_unused_gin_index.sql (19.17ms)13012026/09/22 11:04:26 OK 20251218171726_add_pins.sql (94.11ms)13022026/09/22 11:04:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13032026/09/22 11:04:26 OK 20260628120000_add_object_size_and_stats.sql (73.9ms)13042026/09/22 11:04:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjZiYWYzYjItMDRlYS00YmNkLWI4ZmUtOGM4MmIxZjYwMzYxLjM2OGNhZGIyLWQzZjAtNDBlNC1iM2FmLWMwNTE2ZjlkNTZhZHgxNzkwMDc1MDY0ODY1NjA2MDAw parts=1013052026/09/22 11:04:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13062026/09/22 11:04:26 INFO Completed upload id=113072026/09/22 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures13082026/09/22 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures13092026/09/22 11:04:26 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13102026/09/22 11:04:26 WARN Found objects in DB but missing from S3, will re-upload count=11311--- PASS: TestService_verifyS3Integrity (4.53s)1312=== CONT TestGracefulShutdownDrainsInflight13132026/09/22 11:04:26 INFO Starting HTTP server address=127.0.0.1:6301513142026/09/22 11:04:26 INFO Shutdown signal received, draining in-flight requests timeout=10s13152026/09/22 11:04:26 OK 20260905000000_add_claims.sql (77.46ms)1316--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1317=== CONT TestGCTaskStore_Fail1318--- PASS: TestGCTaskStore_Fail (0.00s)1319=== CONT TestGCTaskStore_PhaseUpdates1320--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1321=== CONT TestGCTaskStore_CompletedAllowsNewTask1322--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1323=== CONT TestGCTaskStore_GetReturnsLatest1324--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1325=== CONT TestGCTaskStore_GetEmpty1326--- PASS: TestGCTaskStore_GetEmpty (0.00s)1327=== CONT TestGCTaskStore_ConflictDifferentParams1328--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1329=== CONT TestGCTaskStore_DeduplicateSameParams1330--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1331=== CONT TestGCTaskStore_StartNew1332--- PASS: TestGCTaskStore_StartNew (0.00s)1333=== CONT TestCompletedNarNotReofferedAcrossClosures13342026/09/22 11:04:26 OK 20260920000000_drop_claims.sql (44.17ms)13352026/09/22 11:04:26 goose: successfully migrated database to version: 2026092000000013362026/09/22 11:04:26 OK 1_commit_pending_closure.sql (3.92ms)13372026/09/22 11:04:26 OK 2_object_stats_trigger.sql (768.92µs)13382026/09/22 11:04:26 goose: up to current file version: 213392026-09-22 11:04:27.039 UTC [94553] ERROR: relation "goose_db_version" does not exist at character 3613402026-09-22 11:04:27.039 UTC [94553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13412026/09/22 11:04:27 INFO lead: acquired remote=192.0.2.1:123413422026/09/22 11:04:27 INFO lead: released remote=192.0.2.1:12341343--- PASS: TestLeadEndsOnShutdown (3.50s)1344=== CONT TestClientWithDependencies13452026/09/22 11:04:27 OK 20241026095416_initial_model.sql (287.81ms)13462026/09/22 11:04:27 OK 20251210153512_drop_unused_gin_index.sql (21.41ms)13472026-09-22 11:04:27.449 UTC [94556] ERROR: relation "goose_db_version" does not exist at character 3613482026-09-22 11:04:27.449 UTC [94556] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13492026/09/22 11:04:27 OK 20251218171726_add_pins.sql (26.89ms)13502026/09/22 11:04:27 OK 20260628120000_add_object_size_and_stats.sql (37.65ms)13512026/09/22 11:04:27 OK 20260905000000_add_claims.sql (80.97ms)13522026/09/22 11:04:27 OK 20260920000000_drop_claims.sql (13.83ms)13532026/09/22 11:04:27 goose: successfully migrated database to version: 2026092000000013542026-09-22 11:04:27.592 UTC [94557] ERROR: relation "goose_db_version" does not exist at character 3613552026-09-22 11:04:27.592 UTC [94557] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/09/22 11:04:27 OK 1_commit_pending_closure.sql (5.73ms)13572026/09/22 11:04:27 OK 2_object_stats_trigger.sql (805.42µs)13582026/09/22 11:04:27 goose: up to current file version: 213592026/09/22 11:04:27 OK 20241026095416_initial_model.sql (149.84ms)13602026/09/22 11:04:27 OK 20251210153512_drop_unused_gin_index.sql (13.53ms)13612026/09/22 11:04:27 OK 20251218171726_add_pins.sql (21.78ms)13622026/09/22 11:04:27 OK 20260628120000_add_object_size_and_stats.sql (50.58ms)13632026/09/22 11:04:27 OK 20260905000000_add_claims.sql (20.59ms)13642026/09/22 11:04:27 OK 20241026095416_initial_model.sql (172.51ms)13652026/09/22 11:04:27 OK 20251210153512_drop_unused_gin_index.sql (12.92ms)13662026/09/22 11:04:27 OK 20260920000000_drop_claims.sql (46.83ms)13672026/09/22 11:04:27 goose: successfully migrated database to version: 2026092000000013682026-09-22 11:04:27.850 UTC [94558] ERROR: relation "goose_db_version" does not exist at character 3613692026-09-22 11:04:27.850 UTC [94558] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13702026/09/22 11:04:27 OK 1_commit_pending_closure.sql (5.39ms)13712026/09/22 11:04:27 OK 2_object_stats_trigger.sql (828.67µs)13722026/09/22 11:04:27 goose: up to current file version: 213732026/09/22 11:04:27 OK 20251218171726_add_pins.sql (49.82ms)13742026/09/22 11:04:27 OK 20260628120000_add_object_size_and_stats.sql (49.09ms)1375--- PASS: TestMetricsInventory (3.62s)1376=== CONT TestService_RequireScope_OIDC13772026/09/22 11:04:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63020/oidc13782026/09/22 11:04:28 OK 20260905000000_add_claims.sql (75.13ms)13792026/09/22 11:04:28 OK 20260920000000_drop_claims.sql (39.29ms)13802026/09/22 11:04:28 goose: successfully migrated database to version: 2026092000000013812026/09/22 11:04:28 OK 1_commit_pending_closure.sql (1.71ms)13822026/09/22 11:04:28 OK 2_object_stats_trigger.sql (405.25µs)13832026/09/22 11:04:28 goose: up to current file version: 213842026/09/22 11:04:28 OK 20241026095416_initial_model.sql (187.63ms)13852026/09/22 11:04:28 OK 20251210153512_drop_unused_gin_index.sql (16.81ms)13862026/09/22 11:04:28 OK 20251218171726_add_pins.sql (43.5ms)13872026/09/22 11:04:28 INFO lead: acquired remote=192.0.2.1:123413882026/09/22 11:04:28 OK 20260628120000_add_object_size_and_stats.sql (47.78ms)13892026/09/22 11:04:28 OK 20260905000000_add_claims.sql (69.29ms)13902026/09/22 11:04:28 INFO lead: released remote=192.0.2.1:123413912026/09/22 11:04:28 OK 20260920000000_drop_claims.sql (40.56ms)13922026/09/22 11:04:28 goose: successfully migrated database to version: 2026092000000013932026/09/22 11:04:28 OK 1_commit_pending_closure.sql (4.34ms)13942026/09/22 11:04:28 OK 2_object_stats_trigger.sql (878.08µs)13952026/09/22 11:04:28 goose: up to current file version: 213962026/09/22 11:04:28 INFO lead: acquired remote=192.0.2.1:123413972026/09/22 11:04:28 INFO lead: released remote=192.0.2.1:12341398--- PASS: TestLeadElectsOneAndHandsOver (3.88s)1399=== CONT TestClientMultipleUploads14002026-09-22 11:04:28.424 UTC [94562] ERROR: relation "goose_db_version" does not exist at character 3614012026-09-22 11:04:28.424 UTC [94562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14022026-09-22 11:04:28.500 UTC [94566] ERROR: relation "goose_db_version" does not exist at character 3614032026-09-22 11:04:28.500 UTC [94566] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14042026/09/22 11:04:28 OK 20241026095416_initial_model.sql (177.77ms)14052026/09/22 11:04:28 OK 20251210153512_drop_unused_gin_index.sql (8.37ms)14062026/09/22 11:04:28 OK 20251218171726_add_pins.sql (38.28ms)14072026/09/22 11:04:28 OK 20260628120000_add_object_size_and_stats.sql (51.85ms)14082026/09/22 11:04:28 OK 20241026095416_initial_model.sql (239.96ms)14092026/09/22 11:04:28 OK 20260905000000_add_claims.sql (50.31ms)14102026/09/22 11:04:28 OK 20251210153512_drop_unused_gin_index.sql (14.26ms)14112026/09/22 11:04:28 OK 20251218171726_add_pins.sql (47.18ms)1412=== NAME TestNARDeduplicationMetadataUploadBug1413 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-94358-4077451566/TestNARDeduplicationMetadataUploadBug1412853602/001/store/j53zwkwnwqppj2cvgylg81319ic77l0l-file1.txt14142026/09/22 11:04:28 OK 20260920000000_drop_claims.sql (65.69ms)14152026/09/22 11:04:28 goose: successfully migrated database to version: 2026092000000014162026/09/22 11:04:28 OK 1_commit_pending_closure.sql (3.12ms)14172026/09/22 11:04:28 OK 2_object_stats_trigger.sql (740.54µs)14182026/09/22 11:04:28 goose: up to current file version: 214192026/09/22 11:04:28 OK 20260628120000_add_object_size_and_stats.sql (54.26ms)14202026/09/22 11:04:28 OK 20260905000000_add_claims.sql (72.73ms)14212026/09/22 11:04:28 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14222026/09/22 11:04:29 OK 20260920000000_drop_claims.sql (53.82ms)14232026/09/22 11:04:29 goose: successfully migrated database to version: 2026092000000014242026/09/22 11:04:29 OK 1_commit_pending_closure.sql (904.79µs)14252026/09/22 11:04:29 OK 2_object_stats_trigger.sql (249.63µs)14262026/09/22 11:04:29 goose: up to current file version: 214272026/09/22 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures14282026/09/22 11:04:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14292026/09/22 11:04:29 INFO Uploading j53zwkwnwqppj2cvgylg81319ic77l0l-file1.txt (160B)14302026-09-22 11:04:29.126 UTC [94577] ERROR: relation "goose_db_version" does not exist at character 3614312026-09-22 11:04:29.126 UTC [94577] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14322026/09/22 11:04:29 WARN Failed to register uploaded object key=j53zwkwnwqppj2cvgylg81319ic77l0l.ls error="server returned 404: 404 page not found\n"14332026/09/22 11:04:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14342026/09/22 11:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14352026/09/22 11:04:29 INFO Signed narinfos id=1 count=114362026/09/22 11:04:29 INFO Uploading 1 narinfos14372026/09/22 11:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14382026/09/22 11:04:29 WARN Failed to register uploaded object key=j53zwkwnwqppj2cvgylg81319ic77l0l.narinfo error="server returned 404: 404 page not found\n"14392026/09/22 11:04:29 INFO Completed upload id=114402026/09/22 11:04:29 INFO Upload complete. (272ms)1441 metadata_upload_test.go:54: Retrieved narinfo from S3:1442 StorePath: /nix/var/nix/builds/nix-94358-4077451566/TestNARDeduplicationMetadataUploadBug1412853602/001/store/j53zwkwnwqppj2cvgylg81319ic77l0l-file1.txt1443 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1444 Compression: zstd1445 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1446 NarSize: 1601447 References: 1448 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1449 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1450 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1451 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1452=== NAME TestPinProtectsFromGC1453 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-94358-4077451566/TestPinProtectsFromGC3868240295/001/store/vc9cgp6i3v241wbc9xa2ldjhs7xcafy2-pinned-file.txt1454 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-94358-4077451566/TestPinProtectsFromGC3868240295/001/store/8ll06aa5b71cn3i13n8bnvg3bdn65a6h-unpinned-file.txt1455=== NAME TestNARDeduplicationMetadataUploadBug1456 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-94358-4077451566/TestNARDeduplicationMetadataUploadBug1412853602/001/store/8zac4wxcjxm8gib4a3z75x6flnmxy8cl-file2.txt14572026/09/22 11:04:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14582026/09/22 11:04:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14592026-09-22 11:04:29.434 UTC [94589] ERROR: relation "goose_db_version" does not exist at character 3614602026-09-22 11:04:29.434 UTC [94589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14612026/09/22 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures14622026/09/22 11:04:29 OK 20241026095416_initial_model.sql (287.47ms)14632026/09/22 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures14642026/09/22 11:04:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14652026/09/22 11:04:29 OK 20251210153512_drop_unused_gin_index.sql (6.59ms)14662026/09/22 11:04:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14672026/09/22 11:04:29 INFO Uploading vc9cgp6i3v241wbc9xa2ldjhs7xcafy2-pinned-file.txt (128B)14682026/09/22 11:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14692026/09/22 11:04:29 INFO Signed narinfos id=2 count=114702026/09/22 11:04:29 INFO Uploading 1 narinfos14712026/09/22 11:04:29 WARN Failed to register uploaded object key=8zac4wxcjxm8gib4a3z75x6flnmxy8cl.ls error="server returned 404: 404 page not found\n"14722026/09/22 11:04:29 WARN readiness check failed error="closed pool"1473--- PASS: TestService_readinessHandler (3.58s)1474=== CONT TestClientIntegration14752026/09/22 11:04:29 OK 20251218171726_add_pins.sql (32.06ms)14762026/09/22 11:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14772026/09/22 11:04:29 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14782026/09/22 11:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14792026/09/22 11:04:29 INFO Completed upload id=214802026/09/22 11:04:29 WARN Failed to register uploaded object key=8zac4wxcjxm8gib4a3z75x6flnmxy8cl.narinfo error="server returned 404: 404 page not found\n"14812026/09/22 11:04:29 INFO Upload complete. (172ms)14822026/09/22 11:04:29 INFO Signed narinfos id=1 count=114832026/09/22 11:04:29 WARN Failed to register uploaded object key=vc9cgp6i3v241wbc9xa2ldjhs7xcafy2.ls error="server returned 404: 404 page not found\n"14842026/09/22 11:04:29 INFO Uploading 1 narinfos1485=== NAME TestNARDeduplicationMetadataUploadBug1486 metadata_upload_test.go:76: Retrieved narinfo from S3:1487 StorePath: /nix/var/nix/builds/nix-94358-4077451566/TestNARDeduplicationMetadataUploadBug1412853602/001/store/8zac4wxcjxm8gib4a3z75x6flnmxy8cl-file2.txt1488 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1489 Compression: zstd1490 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1491 NarSize: 1601492 References: 1493 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1494 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1495 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1496 {"version":1,"root":{"type":"regular","size":44}}14972026/09/22 11:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14982026/09/22 11:04:29 WARN Failed to register uploaded object key=vc9cgp6i3v241wbc9xa2ldjhs7xcafy2.narinfo error="server returned 404: 404 page not found\n"14992026/09/22 11:04:29 OK 20260628120000_add_object_size_and_stats.sql (34.15ms)15002026/09/22 11:04:29 INFO Completed upload id=115012026/09/22 11:04:29 INFO Upload complete. (256ms)1502=== CONT TestClientCADerivations1503--- PASS: TestNARDeduplicationMetadataUploadBug (4.89s)15042026/09/22 11:04:29 OK 20260905000000_add_claims.sql (38.69ms)15052026/09/22 11:04:29 OK 20260920000000_drop_claims.sql (19.29ms)15062026/09/22 11:04:29 goose: successfully migrated database to version: 2026092000000015072026/09/22 11:04:29 OK 1_commit_pending_closure.sql (2.5ms)15082026/09/22 11:04:29 OK 2_object_stats_trigger.sql (401.42µs)15092026/09/22 11:04:29 goose: up to current file version: 215102026/09/22 11:04:29 OK 20241026095416_initial_model.sql (133.05ms)15112026/09/22 11:04:29 OK 20251210153512_drop_unused_gin_index.sql (8.73ms)15122026/09/22 11:04:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15132026/09/22 11:04:29 OK 20251218171726_add_pins.sql (15.69ms)15142026-09-22 11:04:29.669 UTC [94606] ERROR: relation "goose_db_version" does not exist at character 3615152026-09-22 11:04:29.669 UTC [94606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15162026/09/22 11:04:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15172026/09/22 11:04:29 OK 20260628120000_add_object_size_and_stats.sql (29.77ms)15182026/09/22 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures15192026/09/22 11:04:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15202026/09/22 11:04:29 INFO Uploading 8ll06aa5b71cn3i13n8bnvg3bdn65a6h-unpinned-file.txt (128B)15212026/09/22 11:04:29 WARN Failed to register uploaded object key=8ll06aa5b71cn3i13n8bnvg3bdn65a6h.ls error="server returned 404: 404 page not found\n"15222026/09/22 11:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15232026/09/22 11:04:29 INFO Signed narinfos id=2 count=115242026/09/22 11:04:29 INFO Uploading 1 narinfos15252026/09/22 11:04:29 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15262026/09/22 11:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15272026/09/22 11:04:29 WARN Failed to register uploaded object key=8ll06aa5b71cn3i13n8bnvg3bdn65a6h.narinfo error="server returned 404: 404 page not found\n"15282026/09/22 11:04:29 INFO Completed upload id=215292026/09/22 11:04:29 INFO Upload complete. (149ms)15302026/09/22 11:04:29 OK 20260905000000_add_claims.sql (59.29ms)15312026/09/22 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures15322026/09/22 11:04:29 INFO Received create pin request method=POST path=/api/pins/myapp15332026/09/22 11:04:29 OK 20260920000000_drop_claims.sql (27.81ms)15342026/09/22 11:04:29 goose: successfully migrated database to version: 2026092000000015352026/09/22 11:04:29 OK 1_commit_pending_closure.sql (1.03ms)15362026/09/22 11:04:29 OK 2_object_stats_trigger.sql (256.71µs)15372026/09/22 11:04:29 goose: up to current file version: 215382026/09/22 11:04:29 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-94358-4077451566/TestPinProtectsFromGC3868240295/001/store/vc9cgp6i3v241wbc9xa2ldjhs7xcafy2-pinned-file.txt narinfo_key=vc9cgp6i3v241wbc9xa2ldjhs7xcafy2.narinfo15392026/09/22 11:04:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures15402026/09/22 11:04:29 INFO Garbage collection started15412026/09/22 11:04:29 INFO Aborted multipart uploads count=015422026/09/22 11:04:29 WARN Force mode enabled - objects will be deleted immediately without grace period1543--- PASS: TestService_healthCheckHandler (3.40s)1544=== CONT TestCacheStatsHandler15452026/09/22 11:04:29 OK 20241026095416_initial_model.sql (161.24ms)15462026/09/22 11:04:29 OK 20251210153512_drop_unused_gin_index.sql (14.49ms)15472026/09/22 11:04:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15482026/09/22 11:04:29 OK 20251218171726_add_pins.sql (26.01ms)1549=== NAME TestOrphanedObjectsGCStressTest1550 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains15512026/09/22 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures15522026/09/22 11:04:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15532026/09/22 11:04:29 INFO Uploading j4r2aiydvdl77awhvwyn3qap668hgi32-shared-dep (136B)15542026/09/22 11:04:29 OK 20260628120000_add_object_size_and_stats.sql (40ms)15552026/09/22 11:04:29 WARN Failed to register uploaded object key=j4r2aiydvdl77awhvwyn3qap668hgi32.ls error="server returned 404: 404 page not found\n"15562026/09/22 11:04:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15572026/09/22 11:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15582026/09/22 11:04:29 INFO Signed narinfos id=2 count=115592026/09/22 11:04:29 INFO Uploading 1 narinfos15602026/09/22 11:04:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15612026/09/22 11:04:30 WARN Failed to register uploaded object key=j4r2aiydvdl77awhvwyn3qap668hgi32.narinfo error="server returned 404: 404 page not found\n"15622026/09/22 11:04:30 OK 20260905000000_add_claims.sql (50.19ms)1563 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion15642026/09/22 11:04:30 INFO Completed upload id=215652026/09/22 11:04:30 INFO Upload complete. (201ms)15662026/09/22 11:04:30 INFO Received uploads request method=POST path=/api/pending_closures15672026/09/22 11:04:30 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15682026/09/22 11:04:30 INFO Uploading 4kynylnbijj36za0a2k91v2cgca8jq5a-top (256B)15692026/09/22 11:04:30 INFO Uploading j4r2aiydvdl77awhvwyn3qap668hgi32-shared-dep (136B)15702026/09/22 11:04:30 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=015712026/09/22 11:04:30 OK 20260920000000_drop_claims.sql (27.85ms)15722026/09/22 11:04:30 goose: successfully migrated database to version: 2026092000000015732026/09/22 11:04:30 WARN Failed to register uploaded object key=4kynylnbijj36za0a2k91v2cgca8jq5a.ls error="server returned 404: 404 page not found\n"15742026/09/22 11:04:30 WARN Failed to register uploaded object key=nar/1gbrs05f0329mwj5br8wwdng7yk4vdqvakjc4fkx9c79bblyn6dk.nar.zst error="server returned 404: 404 page not found\n"15752026/09/22 11:04:30 OK 1_commit_pending_closure.sql (1.33ms)15762026/09/22 11:04:30 OK 2_object_stats_trigger.sql (293.58µs)15772026/09/22 11:04:30 goose: up to current file version: 215782026/09/22 11:04:30 WARN Failed to register uploaded object key=j4r2aiydvdl77awhvwyn3qap668hgi32.ls error="server returned 404: 404 page not found\n"15792026/09/22 11:04:30 INFO Vacuumed table table=pending_closures15802026/09/22 11:04:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15812026/09/22 11:04:30 INFO Signed narinfos id=1 count=115822026/09/22 11:04:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15832026/09/22 11:04:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15842026/09/22 11:04:30 INFO Signed narinfos id=3 count=115852026/09/22 11:04:30 INFO Uploading 2 narinfos15862026/09/22 11:04:30 INFO Vacuumed table table=pending_objects15872026/09/22 11:04:30 INFO Vacuumed table table=multipart_uploads15882026/09/22 11:04:30 WARN Failed to register uploaded object key=4kynylnbijj36za0a2k91v2cgca8jq5a.narinfo error="server returned 404: 404 page not found\n"15892026/09/22 11:04:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15902026/09/22 11:04:30 WARN Failed to register uploaded object key=j4r2aiydvdl77awhvwyn3qap668hgi32.narinfo error="server returned 404: 404 page not found\n"15912026/09/22 11:04:30 INFO Completed upload id=115922026/09/22 11:04:30 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15932026/09/22 11:04:30 INFO Completed upload id=315942026/09/22 11:04:30 INFO Upload complete. (466ms)1595=== NAME TestClientSharedPathCommittedMidPush1596 client_integration_test.go:680: Retrieved narinfo from S3:1597 StorePath: /nix/var/nix/builds/nix-94358-4077451566/TestClientSharedPathCommittedMidPush2498561364/001/store/j4r2aiydvdl77awhvwyn3qap668hgi32-shared-dep1598 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1599 Compression: zstd1600 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821601 NarSize: 1361602 References: 1603 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16042026-09-22 11:04:30.110 UTC [94628] ERROR: relation "goose_db_version" does not exist at character 3616052026-09-22 11:04:30.110 UTC [94628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16062026/09/22 11:04:30 INFO Vacuumed table table=closures1607 client_integration_test.go:680: Retrieved narinfo from S3:1608 StorePath: /nix/var/nix/builds/nix-94358-4077451566/TestClientSharedPathCommittedMidPush2498561364/001/store/4kynylnbijj36za0a2k91v2cgca8jq5a-top1609 URL: nar/1gbrs05f0329mwj5br8wwdng7yk4vdqvakjc4fkx9c79bblyn6dk.nar.zst1610 Compression: zstd1611 NarHash: sha256:1gbrs05f0329mwj5br8wwdng7yk4vdqvakjc4fkx9c79bblyn6dk1612 NarSize: 2561613 References: /nix/var/nix/builds/nix-94358-4077451566/TestClientSharedPathCommittedMidPush2498561364/001/store/j4r2aiydvdl77awhvwyn3qap668hgi32-shared-dep1614 CA: text:sha256:0qs2kcs5fhl1rlvc2wz0s0nypyqbx99vswpbaaw41m9v6qg1iymm16152026/09/22 11:04:30 INFO Vacuumed table table=objects16162026/09/22 11:04:30 INFO Received uploads request method=POST path=/api/pending_closures1617--- PASS: TestClientSharedPathCommittedMidPush (4.33s)1618=== CONT TestCacheConfigHandler1619=== RUN TestCacheConfigHandler/full_config,_no_issuer1620=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1621=== RUN TestCacheConfigHandler/no_cache_url_configured1622=== PAUSE TestCacheConfigHandler/no_cache_url_configured1623=== RUN TestCacheConfigHandler/no_signing_keys1624=== PAUSE TestCacheConfigHandler/no_signing_keys1625=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1626=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1627=== CONT TestService_ReadScope_PublicByDefault16282026/09/22 11:04:30 OK 20241026095416_initial_model.sql (149.86ms)16292026/09/22 11:04:30 OK 20251210153512_drop_unused_gin_index.sql (13.82ms)16302026/09/22 11:04:30 OK 20251218171726_add_pins.sql (13.7ms)16312026/09/22 11:04:30 OK 20260628120000_add_object_size_and_stats.sql (32.7ms)16322026-09-22 11:04:30.403 UTC [94631] ERROR: relation "goose_db_version" does not exist at character 3616332026-09-22 11:04:30.403 UTC [94631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16342026/09/22 11:04:30 OK 20260905000000_add_claims.sql (52.7ms)16352026/09/22 11:04:30 OK 20260920000000_drop_claims.sql (22.87ms)16362026/09/22 11:04:30 goose: successfully migrated database to version: 2026092000000016372026/09/22 11:04:30 OK 1_commit_pending_closure.sql (1.59ms)16382026/09/22 11:04:30 OK 2_object_stats_trigger.sql (354.54µs)16392026/09/22 11:04:30 goose: up to current file version: 216402026/09/22 11:04:30 OK 20241026095416_initial_model.sql (130.55ms)16412026/09/22 11:04:30 OK 20251210153512_drop_unused_gin_index.sql (7.42ms)16422026/09/22 11:04:30 OK 20251218171726_add_pins.sql (34.81ms)16432026/09/22 11:04:30 OK 20260628120000_add_object_size_and_stats.sql (28.33ms)1644=== RUN TestService_RequireScope_OIDC/builder_may_write1645=== PAUSE TestService_RequireScope_OIDC/builder_may_write1646=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1647=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1648=== RUN TestService_RequireScope_OIDC/ops_may_admin1649=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1650=== RUN TestService_RequireScope_OIDC/ops_may_not_write1651=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1652=== RUN TestService_RequireScope_OIDC/reader_may_not_write1653=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1654=== RUN TestService_RequireScope_OIDC/static_token_may_admin1655=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1656=== RUN TestService_RequireScope_OIDC/static_token_may_write1657=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1658=== RUN TestService_RequireScope_OIDC/reader_may_read1659=== PAUSE TestService_RequireScope_OIDC/reader_may_read1660=== RUN TestService_RequireScope_OIDC/writer_implies_read1661=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1662=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1663=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1664=== CONT TestSkippedUploadsHandler16652026/09/22 11:04:30 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001666--- PASS: TestSkippedUploadsHandler (0.00s)1667=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle16682026/09/22 11:04:30 OK 20260905000000_add_claims.sql (52ms)16692026/09/22 11:04:30 OK 20260920000000_drop_claims.sql (11.47ms)16702026/09/22 11:04:30 goose: successfully migrated database to version: 2026092000000016712026/09/22 11:04:30 OK 1_commit_pending_closure.sql (1.32ms)16722026/09/22 11:04:30 OK 2_object_stats_trigger.sql (231µs)16732026/09/22 11:04:30 goose: up to current file version: 21674=== NAME TestClientWithDependencies1675 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-94358-4077451566/TestClientWithDependencies2395701942/001/store/07z39yl8yxrrlip2cfc0c149phskqgkk-test-script1676 client_integration_test.go:615: Found 1 dependencies (including self)16772026/09/22 11:04:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16782026/09/22 11:04:30 INFO Received uploads request method=POST path=/api/pending_closures16792026/09/22 11:04:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16802026/09/22 11:04:30 INFO Uploading 07z39yl8yxrrlip2cfc0c149phskqgkk-test-script (136B)16812026/09/22 11:04:30 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16822026/09/22 11:04:30 WARN Failed to register uploaded object key=07z39yl8yxrrlip2cfc0c149phskqgkk.ls error="server returned 404: 404 page not found\n"16832026/09/22 11:04:30 WARN Failed to register uploaded object key=log/9rql4iwhnxdpkcwrvr2h1a2gjwfj4f7z-test-script.drv error="server returned 404: 404 page not found\n"16842026/09/22 11:04:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16852026/09/22 11:04:30 INFO Signed narinfos id=1 count=116862026/09/22 11:04:30 INFO Uploading 1 narinfos16872026/09/22 11:04:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16882026/09/22 11:04:30 WARN Failed to register uploaded object key=07z39yl8yxrrlip2cfc0c149phskqgkk.narinfo error="server returned 404: 404 page not found\n"16892026/09/22 11:04:30 INFO Completed upload id=116902026/09/22 11:04:30 INFO Upload complete. (159ms)1691 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-94358-4077451566/TestClientWithDependencies2395701942/001/store) requires matching store prefix1692--- PASS: TestClientWithDependencies (3.86s)1693=== CONT TestService_ReadAuthMiddleware1694=== NAME TestClientMultipleUploads1695 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-94358-4077451566/TestClientMultipleUploads4260994665/001/store/vqjv01n8n9lqs3zg20k76jmy7z5bxlj9-test-file-0.txt16962026-09-22 11:04:31.101 UTC [94648] ERROR: relation "goose_db_version" does not exist at character 3616972026-09-22 11:04:31.101 UTC [94648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1698 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-94358-4077451566/TestClientMultipleUploads4260994665/001/store/r48wkiwal5kramq9gf4my42d13y3r8z0-test-file-1.txt16992026-09-22 11:04:31.136 UTC [94653] ERROR: relation "goose_db_version" does not exist at character 3617002026-09-22 11:04:31.136 UTC [94653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17012026-09-22 11:04:31.138 UTC [94654] ERROR: relation "goose_db_version" does not exist at character 3617022026-09-22 11:04:31.138 UTC [94654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17032026/09/22 11:04:31 OK 20241026095416_initial_model.sql (52.01ms)17042026/09/22 11:04:31 OK 20251210153512_drop_unused_gin_index.sql (7.83ms)1705 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-94358-4077451566/TestClientMultipleUploads4260994665/001/store/01b7h6wnlxwsshiiw6dz9g8ssa34pqfv-test-file-2.txt17062026/09/22 11:04:31 OK 20251218171726_add_pins.sql (7.73ms)17072026/09/22 11:04:31 OK 20260628120000_add_object_size_and_stats.sql (7.36ms)17082026/09/22 11:04:31 OK 20260905000000_add_claims.sql (2.59ms)17092026/09/22 11:04:31 OK 20241026095416_initial_model.sql (32.89ms)17102026/09/22 11:04:31 OK 20241026095416_initial_model.sql (49.38ms)17112026/09/22 11:04:31 OK 20251210153512_drop_unused_gin_index.sql (775.04µs)17122026/09/22 11:04:31 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)17132026/09/22 11:04:31 OK 20260920000000_drop_claims.sql (1.74ms)17142026/09/22 11:04:31 goose: successfully migrated database to version: 2026092000000017152026/09/22 11:04:31 OK 1_commit_pending_closure.sql (1.18ms)17162026/09/22 11:04:31 OK 2_object_stats_trigger.sql (355.88µs)17172026/09/22 11:04:31 goose: up to current file version: 217182026/09/22 11:04:31 OK 20251218171726_add_pins.sql (3.46ms)17192026/09/22 11:04:31 OK 20251218171726_add_pins.sql (4.06ms)17202026/09/22 11:04:31 OK 20260628120000_add_object_size_and_stats.sql (36.78ms)17212026/09/22 11:04:31 OK 20260628120000_add_object_size_and_stats.sql (45.79ms)17222026/09/22 11:04:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17232026/09/22 11:04:31 OK 20260905000000_add_claims.sql (41.18ms)17242026/09/22 11:04:31 OK 20260905000000_add_claims.sql (41.3ms)17252026/09/22 11:04:31 OK 20260920000000_drop_claims.sql (22.58ms)17262026/09/22 11:04:31 goose: successfully migrated database to version: 2026092000000017272026/09/22 11:04:31 OK 20260920000000_drop_claims.sql (13.88ms)17282026/09/22 11:04:31 goose: successfully migrated database to version: 2026092000000017292026/09/22 11:04:31 OK 1_commit_pending_closure.sql (1.62ms)17302026/09/22 11:04:31 OK 1_commit_pending_closure.sql (1.56ms)17312026/09/22 11:04:31 OK 2_object_stats_trigger.sql (484.25µs)17322026/09/22 11:04:31 goose: up to current file version: 217332026/09/22 11:04:31 OK 2_object_stats_trigger.sql (328.17µs)17342026/09/22 11:04:31 goose: up to current file version: 217352026-09-22 11:04:31.328 UTC [94662] ERROR: relation "goose_db_version" does not exist at character 3617362026-09-22 11:04:31.328 UTC [94662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17372026/09/22 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures17382026/09/22 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures17392026/09/22 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures17402026/09/22 11:04:31 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17412026/09/22 11:04:31 INFO Uploading vqjv01n8n9lqs3zg20k76jmy7z5bxlj9-test-file-0.txt (160B)17422026/09/22 11:04:31 INFO Uploading 01b7h6wnlxwsshiiw6dz9g8ssa34pqfv-test-file-2.txt (160B)17432026/09/22 11:04:31 INFO Uploading r48wkiwal5kramq9gf4my42d13y3r8z0-test-file-1.txt (160B)17442026/09/22 11:04:31 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17452026/09/22 11:04:31 WARN Failed to register uploaded object key=01b7h6wnlxwsshiiw6dz9g8ssa34pqfv.ls error="server returned 404: 404 page not found\n"17462026/09/22 11:04:31 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17472026/09/22 11:04:31 WARN Failed to register uploaded object key=vqjv01n8n9lqs3zg20k76jmy7z5bxlj9.ls error="server returned 404: 404 page not found\n"17482026/09/22 11:04:31 WARN Failed to register uploaded object key=r48wkiwal5kramq9gf4my42d13y3r8z0.ls error="server returned 404: 404 page not found\n"17492026/09/22 11:04:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign17502026/09/22 11:04:31 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17512026/09/22 11:04:31 INFO Signed narinfos id=3 count=117522026/09/22 11:04:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17532026/09/22 11:04:31 INFO Signed narinfos id=1 count=117542026/09/22 11:04:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17552026/09/22 11:04:31 INFO Signed narinfos id=2 count=117562026/09/22 11:04:31 INFO Uploading 3 narinfos17572026/09/22 11:04:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17582026/09/22 11:04:31 WARN Failed to register uploaded object key=r48wkiwal5kramq9gf4my42d13y3r8z0.narinfo error="server returned 404: 404 page not found\n"17592026/09/22 11:04:31 WARN Failed to register uploaded object key=vqjv01n8n9lqs3zg20k76jmy7z5bxlj9.narinfo error="server returned 404: 404 page not found\n"17602026/09/22 11:04:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17612026/09/22 11:04:31 WARN Failed to register uploaded object key=01b7h6wnlxwsshiiw6dz9g8ssa34pqfv.narinfo error="server returned 404: 404 page not found\n"17622026/09/22 11:04:31 INFO Completed upload id=117632026/09/22 11:04:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17642026/09/22 11:04:31 INFO Completed upload id=217652026/09/22 11:04:31 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17662026/09/22 11:04:31 INFO Completed upload id=317672026/09/22 11:04:31 INFO Upload complete. (200ms)1768 client_integration_test.go:369: Uploaded 3 paths in 236.693125ms17692026/09/22 11:04:31 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjZiYWYzYjItMDRlYS00YmNkLWI4ZmUtOGM4MmIxZjYwMzYxLjI1MzE1MTZmLTQwNzYtNDM2NS04OTY1LTc5Y2NlY2YwZTQ0ZngxNzkwMDc1MDcwMTYzNDAxMDAw parts=1217702026/09/22 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures1771--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.65s)1772=== CONT TestService_AuthMiddleware_OIDC1773--- PASS: TestClientMultipleUploads (3.09s)1774=== CONT TestParseSize1775--- PASS: TestParseSize (0.00s)1776=== CONT TestService_Rustfstest17772026/09/22 11:04:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63085/oidc17782026/09/22 11:04:31 OK 20241026095416_initial_model.sql (152.35ms)17792026/09/22 11:04:31 OK 20251210153512_drop_unused_gin_index.sql (9.65ms)17802026/09/22 11:04:31 OK 20251218171726_add_pins.sql (9.66ms)17812026/09/22 11:04:31 OK 20260628120000_add_object_size_and_stats.sql (17.41ms)17822026/09/22 11:04:31 OK 20260905000000_add_claims.sql (18.28ms)1783=== NAME TestClientIntegration1784 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-94358-4077451566/TestClientIntegration3200627532/002/store/xmp4lz647jlmwpd7aw0wbyzps542khb4-test-file.txt17852026/09/22 11:04:31 OK 20260920000000_drop_claims.sql (14.7ms)17862026/09/22 11:04:31 goose: successfully migrated database to version: 2026092000000017872026/09/22 11:04:31 OK 1_commit_pending_closure.sql (1.18ms)17882026/09/22 11:04:31 OK 2_object_stats_trigger.sql (457.63µs)17892026/09/22 11:04:31 goose: up to current file version: 217902026/09/22 11:04:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1791--- PASS: TestCacheStatsHandler (1.82s)1792=== CONT TestProxyWriteTimeout/unknown_size1793=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17942026/09/22 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures17952026/09/22 11:04:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17962026/09/22 11:04:31 INFO Uploading xmp4lz647jlmwpd7aw0wbyzps542khb4-test-file.txt (152B)17972026/09/22 11:04:31 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17982026/09/22 11:04:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17992026/09/22 11:04:31 INFO Signed narinfos id=1 count=118002026/09/22 11:04:31 WARN Failed to register uploaded object key=xmp4lz647jlmwpd7aw0wbyzps542khb4.ls error="server returned 404: 404 page not found\n"18012026/09/22 11:04:31 INFO Uploading 1 narinfos18022026/09/22 11:04:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18032026/09/22 11:04:31 WARN Failed to register uploaded object key=xmp4lz647jlmwpd7aw0wbyzps542khb4.narinfo error="server returned 404: 404 page not found\n"18042026/09/22 11:04:31 INFO Completed upload id=118052026/09/22 11:04:31 INFO Upload complete. (154ms)18062026/09/22 11:04:31 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01807=== NAME TestPinProtectsFromGC1808 client_integration_test.go:794: Pin successfully protected closure from garbage collection18092026/09/22 11:04:31 INFO All 1 paths already cached1810=== NAME TestClientIntegration1811 client_integration_test.go:312: Retrieved narinfo from S3:1812 StorePath: /nix/var/nix/builds/nix-94358-4077451566/TestClientIntegration3200627532/002/store/xmp4lz647jlmwpd7aw0wbyzps542khb4-test-file.txt1813 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1814 Compression: zstd1815 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11816 NarSize: 1521817 References: 1818 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118192026-09-22 11:04:31.822 UTC [94677] ERROR: relation "goose_db_version" does not exist at character 3618202026-09-22 11:04:31.822 UTC [94677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1821 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1822 client_integration_test.go:313: Decompressed .ls content (64 bytes):1823 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1824 client_integration_test.go:316: Testing garbage collection...1825--- PASS: TestPinProtectsFromGC (6.60s)1826=== CONT TestProxyWriteTimeout/10_GiB_nar1827=== CONT TestService_AuthMiddleware_MTLSProxyHeader18282026/09/22 11:04:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures18292026/09/22 11:04:31 INFO Garbage collection started18302026/09/22 11:04:31 INFO Aborted multipart uploads count=018312026/09/22 11:04:31 WARN Force mode enabled - objects will be deleted immediately without grace period18322026/09/22 11:04:31 OK 20241026095416_initial_model.sql (128.94ms)18332026/09/22 11:04:32 OK 20251210153512_drop_unused_gin_index.sql (8.51ms)18342026/09/22 11:04:32 OK 20251218171726_add_pins.sql (18.51ms)18352026/09/22 11:04:32 OK 20260628120000_add_object_size_and_stats.sql (61.05ms)1836=== NAME TestOrphanedObjectsGCStressTest1837 orphaned_objects_gc_test.go:509: Stress test completed successfully:1838 orphaned_objects_gc_test.go:510: - Active objects preserved: 201839 orphaned_objects_gc_test.go:511: - Objects deleted: 2101840 orphaned_objects_gc_test.go:512: - Total GC'd: 2101841--- PASS: TestOrphanedObjectsGCStressTest (10.99s)1842=== CONT TestProxyWriteTimeout/1_GiB_nar1843--- PASS: TestProxyWriteTimeout (0.00s)1844 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1845 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1846 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1847 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1848=== CONT TestCompleteMultipartUpload_ErrorButObjectExists18492026/09/22 11:04:32 OK 20260905000000_add_claims.sql (43.49ms)1850--- PASS: TestService_ReadScope_PublicByDefault (1.96s)1851=== CONT TestIsValidCachePath/narinfo1852=== CONT TestIsValidCachePath/leading_slash1853=== CONT TestIsValidCachePath/empty1854=== CONT TestIsValidCachePath/random_path1855=== CONT TestIsValidCachePath/invalid_char_u1856=== CONT TestIsValidCachePath/invalid_char_e1857=== CONT TestIsValidCachePath/traversal_in_middle1858=== CONT TestIsValidCachePath/traversal_parent1859=== CONT TestIsValidCachePath/wrong_extension1860=== CONT TestIsValidCachePath/short_hash1861=== CONT TestIsValidCachePath/nar_uncompressed1862=== CONT TestIsValidCachePath/nix-cache-info1863=== CONT TestIsValidCachePath/realisation1864=== CONT TestIsValidCachePath/log1865=== CONT TestIsValidCachePath/ls1866=== CONT TestIsValidCachePath/nar_xz1867=== CONT TestIsValidCachePath/nar_bz21868=== CONT TestIsValidCachePath/nar_zst1869=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1870=== CONT TestIsValidCachePath/index.html1871--- PASS: TestIsValidCachePath (0.00s)1872 --- PASS: TestIsValidCachePath/narinfo (0.00s)1873 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1874 --- PASS: TestIsValidCachePath/empty (0.00s)1875 --- PASS: TestIsValidCachePath/random_path (0.00s)1876 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1877 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1878 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1879 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1880 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1881 --- PASS: TestIsValidCachePath/short_hash (0.00s)1882 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1883 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1884 --- PASS: TestIsValidCachePath/realisation (0.00s)1885 --- PASS: TestIsValidCachePath/log (0.00s)1886 --- PASS: TestIsValidCachePath/ls (0.00s)1887 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1888 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1889 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1890 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1891 --- PASS: TestIsValidCachePath/index.html (0.00s)1892=== CONT TestParseSingleRange/none1893=== CONT TestParseSingleRange/open-ended1894=== CONT TestParseSingleRange/start_far_past_EOF1895=== CONT TestParseSingleRange/start_past_EOF1896=== CONT TestParseSingleRange/single_byte1897=== CONT TestParseSingleRange/suffix_exceeds_size1898=== CONT TestParseSingleRange/suffix1899=== CONT TestParseSingleRange/end_clamped_to_size1900=== CONT TestParseSingleRange/malformed_both_empty1901=== CONT TestParseSingleRange/closed1902=== CONT TestParseSingleRange/malformed_end_before_start1903=== CONT TestParseSingleRange/unknown_unit1904=== CONT TestParseSingleRange/malformed_no_dash1905=== CONT TestParseSingleRange/multi-range_ignored1906--- PASS: TestParseSingleRange (0.00s)1907 --- PASS: TestParseSingleRange/none (0.00s)1908 --- PASS: TestParseSingleRange/open-ended (0.00s)1909 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1910 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1911 --- PASS: TestParseSingleRange/single_byte (0.00s)1912 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1913 --- PASS: TestParseSingleRange/suffix (0.00s)1914 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1915 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1916 --- PASS: TestParseSingleRange/closed (0.00s)1917 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1918 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1919 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1920 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1921=== CONT TestClientErrorHandling/InvalidStorePath19222026/09/22 11:04:32 OK 20260920000000_drop_claims.sql (15.34ms)19232026/09/22 11:04:32 goose: successfully migrated database to version: 2026092000000019242026/09/22 11:04:32 OK 1_commit_pending_closure.sql (2.45ms)19252026/09/22 11:04:32 OK 2_object_stats_trigger.sql (638.13µs)19262026/09/22 11:04:32 goose: up to current file version: 219272026-09-22 11:04:32.175 UTC [94694] ERROR: relation "goose_db_version" does not exist at character 3619282026-09-22 11:04:32.175 UTC [94694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19292026/09/22 11:04:32 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=019302026/09/22 11:04:32 INFO Vacuumed table table=pending_closures19312026/09/22 11:04:32 INFO Vacuumed table table=pending_objects19322026/09/22 11:04:32 INFO Vacuumed table table=multipart_uploads19332026/09/22 11:04:32 INFO Vacuumed table table=closures19342026/09/22 11:04:32 INFO Vacuumed table table=objects1935=== NAME TestClientCADerivations1936 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-94358-4077451566/TestClientCADerivations2322536590/001/store/byfb44yifl3nhjdnqd7ryzvijv5zynwz-ca-test19372026/09/22 11:04:32 INFO Received uploads request method=POST path=/api/pending_closures19382026/09/22 11:04:32 OK 20241026095416_initial_model.sql (155.72ms)19392026/09/22 11:04:32 OK 20251210153512_drop_unused_gin_index.sql (5.37ms)19402026/09/22 11:04:32 OK 20251218171726_add_pins.sql (18.97ms)1941 client_ca_test.go:139: Found 1 dependencies (including self)19422026/09/22 11:04:32 OK 20260628120000_add_object_size_and_stats.sql (18.14ms)19432026/09/22 11:04:32 OK 20260905000000_add_claims.sql (13.26ms)19442026/09/22 11:04:32 OK 20260920000000_drop_claims.sql (1.59ms)19452026/09/22 11:04:32 goose: successfully migrated database to version: 2026092000000019462026/09/22 11:04:32 OK 1_commit_pending_closure.sql (835.88µs)19472026/09/22 11:04:32 OK 2_object_stats_trigger.sql (233.42µs)19482026/09/22 11:04:32 goose: up to current file version: 219492026/09/22 11:04:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19502026/09/22 11:04:32 INFO Received uploads request method=POST path=/api/pending_closures19512026/09/22 11:04:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19522026/09/22 11:04:32 INFO Uploading byfb44yifl3nhjdnqd7ryzvijv5zynwz-ca-test (144B)19532026/09/22 11:04:32 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19542026/09/22 11:04:32 WARN Failed to register uploaded object key=byfb44yifl3nhjdnqd7ryzvijv5zynwz.ls error="server returned 404: 404 page not found\n"19552026/09/22 11:04:32 WARN Failed to register uploaded object key=log/811mcbj1mh38q9jfnhr3vcwdrbjx8c1x-ca-test.drv error="server returned 404: 404 page not found\n"19562026/09/22 11:04:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19572026/09/22 11:04:32 INFO Signed narinfos id=1 count=119582026/09/22 11:04:32 INFO Uploading 1 narinfos19592026/09/22 11:04:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19602026/09/22 11:04:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19612026/09/22 11:04:32 WARN Failed to register uploaded object key=byfb44yifl3nhjdnqd7ryzvijv5zynwz.narinfo error="server returned 404: 404 page not found\n"19622026/09/22 11:04:32 INFO Completed upload id=119632026/09/22 11:04:32 INFO Upload complete. (217ms)1964 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-94358-4077451566/TestClientCADerivations2322536590/001/store/byfb44yifl3nhjdnqd7ryzvijv5zynwz-ca-test1965 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1966 Compression: zstd1967 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1968 NarSize: 1441969 References: 1970 Deriver: /nix/var/nix/builds/nix-94358-4077451566/TestClientCADerivations2322536590/001/store/811mcbj1mh38q9jfnhr3vcwdrbjx8c1x-ca-test.drv1971 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1972 client_ca_test.go:185: Checking for realisation files in S3...1973 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1974 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1975--- PASS: TestService_ReadAuthMiddleware (1.63s)1976=== CONT TestClientErrorHandling/ServerNotAvailable1977=== NAME TestClientCADerivations1978 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket47?endpoint=http://localhost:62932®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-94358-4077451566/TestClientCADerivations2322536590/001/store'1979 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119802026-09-22 11:04:32.730 UTC [94707] ERROR: relation "goose_db_version" does not exist at character 3619812026-09-22 11:04:32.730 UTC [94707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1982--- PASS: TestClientCADerivations (3.17s)1983=== CONT TestClientErrorHandling/InvalidAuthToken19842026-09-22 11:04:32.752 UTC [94710] ERROR: relation "goose_db_version" does not exist at character 3619852026-09-22 11:04:32.752 UTC [94710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19862026-09-22 11:04:32.773 UTC [94713] ERROR: relation "goose_db_version" does not exist at character 3619872026-09-22 11:04:32.773 UTC [94713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19882026/09/22 11:04:32 OK 20241026095416_initial_model.sql (27.23ms)19892026/09/22 11:04:32 OK 20251210153512_drop_unused_gin_index.sql (377.79µs)19902026/09/22 11:04:32 OK 20251218171726_add_pins.sql (1.2ms)19912026/09/22 11:04:32 OK 20241026095416_initial_model.sql (21.25ms)19922026/09/22 11:04:32 OK 20260628120000_add_object_size_and_stats.sql (6.48ms)19932026/09/22 11:04:32 OK 20241026095416_initial_model.sql (8.06ms)19942026/09/22 11:04:32 OK 20251210153512_drop_unused_gin_index.sql (455.04µs)19952026/09/22 11:04:32 OK 20251210153512_drop_unused_gin_index.sql (391.42µs)19962026/09/22 11:04:32 OK 20260905000000_add_claims.sql (1.14ms)19972026/09/22 11:04:32 OK 20251218171726_add_pins.sql (854.38µs)19982026/09/22 11:04:32 OK 20251218171726_add_pins.sql (797µs)19992026/09/22 11:04:32 OK 20260920000000_drop_claims.sql (654.79µs)20002026/09/22 11:04:32 goose: successfully migrated database to version: 2026092000000020012026/09/22 11:04:32 OK 1_commit_pending_closure.sql (801µs)20022026/09/22 11:04:32 OK 2_object_stats_trigger.sql (207.5µs)20032026/09/22 11:04:32 goose: up to current file version: 220042026/09/22 11:04:32 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/present20052026/09/22 11:04:32 OK 20260628120000_add_object_size_and_stats.sql (18.57ms)20062026/09/22 11:04:32 OK 20260628120000_add_object_size_and_stats.sql (19.16ms)20072026/09/22 11:04:32 OK 20260905000000_add_claims.sql (20.87ms)20082026/09/22 11:04:32 OK 20260920000000_drop_claims.sql (7.59ms)20092026/09/22 11:04:32 goose: successfully migrated database to version: 2026092000000020102026/09/22 11:04:32 OK 20260905000000_add_claims.sql (29.07ms)20112026/09/22 11:04:32 OK 1_commit_pending_closure.sql (1.2ms)20122026/09/22 11:04:32 OK 20260920000000_drop_claims.sql (1.27ms)20132026/09/22 11:04:32 goose: successfully migrated database to version: 2026092000000020142026/09/22 11:04:32 OK 2_object_stats_trigger.sql (348.08µs)20152026/09/22 11:04:32 goose: up to current file version: 220162026/09/22 11:04:32 OK 1_commit_pending_closure.sql (777.5µs)20172026/09/22 11:04:32 OK 2_object_stats_trigger.sql (210.63µs)20182026/09/22 11:04:32 goose: up to current file version: 220192026/09/22 11:04:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.642211ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2020--- PASS: TestService_Rustfstest (1.46s)2021=== CONT TestServerTLSConfig/no_client_CA2022=== CONT TestServerTLSConfig/not_a_PEM_file2023=== CONT TestServerTLSConfig/missing_CA_file2024--- PASS: TestServerTLSConfig (0.00s)2025 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2026 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2027 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2028=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20292026/09/22 11:04:32 INFO Received uploads request method=POST path=/20302026-09-22 11:04:33.028 UTC [94715] ERROR: relation "goose_db_version" does not exist at character 3620312026-09-22 11:04:33.028 UTC [94715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20322026/09/22 11:04:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.200445ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20332026/09/22 11:04:33 OK 20241026095416_initial_model.sql (52.8ms)20342026/09/22 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)20352026/09/22 11:04:33 OK 20251218171726_add_pins.sql (7.09ms)2036=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2037=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2038=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2039=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2040=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2041=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2042=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2043=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2044=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20452026/09/22 11:04:33 INFO Received request for more parts method=POST path=/20462026/09/22 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (14.21ms)20472026-09-22 11:04:33.140 UTC [94716] ERROR: relation "goose_db_version" does not exist at character 3620482026-09-22 11:04:33.140 UTC [94716] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2049=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20502026/09/22 11:04:33 INFO Received complete multipart upload request method=POST path=/2051=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20522026/09/22 11:04:33 INFO Received uploads request method=POST path=/2053=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20542026/09/22 11:04:33 INFO Received complete multipart upload request method=POST path=/2055=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20562026/09/22 11:04:33 INFO Received request for more parts method=POST path=/2057=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20582026/09/22 11:04:33 INFO Received uploads request method=POST path=/2059--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2060 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2061 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2062 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2063 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2064=== CONT TestIsValidUploadKey/narinfo2065=== CONT TestIsValidUploadKey/realisation_plus_in_output2066=== CONT TestIsValidUploadKey/unknown_type2067=== CONT TestIsValidUploadKey/empty_key2068=== CONT TestIsValidUploadKey/absolute2069=== CONT TestIsValidUploadKey/traversal_nar2070=== CONT TestIsValidUploadKey/traversal2071=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2072=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2073=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2074=== CONT TestIsValidUploadKey/index.html2075=== CONT TestIsValidUploadKey/nix-cache-info2076=== CONT TestIsValidUploadKey/build_log_home-manager_file2077=== CONT TestIsValidUploadKey/realisation2078=== CONT TestIsValidUploadKey/build_log_equals2079=== CONT TestIsValidUploadKey/build_log_question_mark2080=== CONT TestIsValidUploadKey/build_log_plus_in_name2081=== CONT TestIsValidUploadKey/nar_plain2082=== CONT TestIsValidUploadKey/build_log2083=== CONT TestIsValidUploadKey/listing2084=== CONT TestIsValidUploadKey/nar_xz2085=== CONT TestIsValidUploadKey/nar_zst2086--- PASS: TestIsValidUploadKey (0.00s)2087 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2088 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2089 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2090 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2091 --- PASS: TestIsValidUploadKey/absolute (0.00s)2092 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2093 --- PASS: TestIsValidUploadKey/traversal (0.00s)2094 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2095 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2096 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2097 --- PASS: TestIsValidUploadKey/index.html (0.00s)2098 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2099 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2100 --- PASS: TestIsValidUploadKey/realisation (0.00s)2101 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2102 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2103 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2104 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2105 --- PASS: TestIsValidUploadKey/build_log (0.00s)2106 --- PASS: TestIsValidUploadKey/listing (0.00s)2107 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2108 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2109=== CONT TestResolveDBConnectionString/flag_wins2110=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2111=== CONT TestResolveDBConnectionString/nothing_configured2112=== CONT TestResolveDBConnectionString/missing_file_is_an_error2113=== CONT TestResolveDBConnectionString/file_when_flag_empty2114=== CONT TestCacheConfigHandler/full_config,_no_issuer2115=== CONT TestCacheConfigHandler/no_signing_keys2116=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2117=== CONT TestCacheConfigHandler/no_cache_url_configured2118--- PASS: TestCacheConfigHandler (0.00s)2119 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2120 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2121 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2122 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2123=== CONT TestService_RequireScope_OIDC/builder_may_write2124=== CONT TestService_RequireScope_OIDC/static_token_may_admin2125=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2126=== CONT TestService_RequireScope_OIDC/writer_implies_read2127=== CONT TestService_RequireScope_OIDC/reader_may_read2128=== CONT TestService_RequireScope_OIDC/static_token_may_write2129=== CONT TestService_RequireScope_OIDC/reader_may_not_write2130=== CONT TestService_RequireScope_OIDC/ops_may_admin2131=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2132=== CONT TestService_RequireScope_OIDC/ops_may_not_write2133=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2134=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21352026/09/22 11:04:33 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]2136=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2137=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21382026/09/22 11:04:33 WARN Authentication failed token_preview=eyJhbGciOi...yXIcYPAUag token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2139--- PASS: TestService_AuthMiddleware_OIDC (1.67s)2140 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2141 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2142 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2143 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2144--- PASS: TestResolveDBConnectionString (0.01s)2145 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2146 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2147 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2148 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2149 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2150--- PASS: TestService_RequireScope_OIDC (2.71s)2151 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2152 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2153 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2154 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2155 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2156 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2157 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2158 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2159 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2160 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)21612026/09/22 11:04:33 OK 20260905000000_add_claims.sql (41ms)21622026/09/22 11:04:33 OK 20260920000000_drop_claims.sql (1.28ms)21632026/09/22 11:04:33 goose: successfully migrated database to version: 2026092000000021642026/09/22 11:04:33 OK 1_commit_pending_closure.sql (893.25µs)21652026/09/22 11:04:33 OK 2_object_stats_trigger.sql (438.13µs)21662026/09/22 11:04:33 goose: up to current file version: 221672026-09-22 11:04:33.178 UTC [94717] ERROR: relation "goose_db_version" does not exist at character 3621682026-09-22 11:04:33.178 UTC [94717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21692026/09/22 11:04:33 OK 20241026095416_initial_model.sql (24.95ms)21702026/09/22 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (6.83ms)21712026/09/22 11:04:33 OK 20251218171726_add_pins.sql (5.48ms)21722026/09/22 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)21732026/09/22 11:04:33 OK 20260905000000_add_claims.sql (5.92ms)2174--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)2175 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2176 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2177 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)21782026/09/22 11:04:33 OK 20241026095416_initial_model.sql (32.99ms)21792026/09/22 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)21802026/09/22 11:04:33 OK 20260920000000_drop_claims.sql (9.27ms)21812026/09/22 11:04:33 goose: successfully migrated database to version: 2026092000000021822026/09/22 11:04:33 OK 1_commit_pending_closure.sql (862.46µs)21832026/09/22 11:04:33 OK 2_object_stats_trigger.sql (229.25µs)21842026/09/22 11:04:33 goose: up to current file version: 221852026/09/22 11:04:33 OK 20251218171726_add_pins.sql (10.31ms)21862026/09/22 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (6.64ms)21872026/09/22 11:04:33 OK 20260905000000_add_claims.sql (7.52ms)21882026/09/22 11:04:33 OK 20260920000000_drop_claims.sql (7.71ms)21892026/09/22 11:04:33 goose: successfully migrated database to version: 2026092000000021902026/09/22 11:04:33 OK 1_commit_pending_closure.sql (781.21µs)21912026/09/22 11:04:33 OK 2_object_stats_trigger.sql (186.46µs)21922026/09/22 11:04:33 goose: up to current file version: 221932026/09/22 11:04:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21942026/09/22 11:04:33 WARN mTLS auth: bound subjects configured but subject DN unavailable21952026/09/22 11:04:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2196--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.61s)21972026-09-22 11:04:33.339 UTC [94718] ERROR: relation "goose_db_version" does not exist at character 3621982026-09-22 11:04:33.339 UTC [94718] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21992026/09/22 11:04:33 OK 20241026095416_initial_model.sql (40.27ms)22002026/09/22 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (5.66ms)22012026/09/22 11:04:33 OK 20251218171726_add_pins.sql (5.98ms)22022026/09/22 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (7.16ms)22032026/09/22 11:04:33 OK 20260905000000_add_claims.sql (20.86ms)22042026/09/22 11:04:33 OK 20260920000000_drop_claims.sql (21.71ms)22052026/09/22 11:04:33 goose: successfully migrated database to version: 202609200000002206--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.60s)22072026/09/22 11:04:33 OK 1_commit_pending_closure.sql (3.27ms)22082026/09/22 11:04:33 OK 2_object_stats_trigger.sql (817.83µs)22092026/09/22 11:04:33 goose: up to current file version: 222102026/09/22 11:04:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=798.563107ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22112026/09/22 11:04:33 INFO Received uploads request method=POST path=/api/pending_closures22122026/09/22 11:04:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22132026/09/22 11:04:33 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjZiYWYzYjItMDRlYS00YmNkLWI4ZmUtOGM4MmIxZjYwMzYxLmYxZjI2ZWQwLTc1YTctNGExNy05NWE1LTEyODFmZmQzOWU0NHgxNzkwMDc1MDczNjc1MDI2MDAw22142026/09/22 11:04:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjZiYWYzYjItMDRlYS00YmNkLWI4ZmUtOGM4MmIxZjYwMzYxLmYxZjI2ZWQwLTc1YTctNGExNy05NWE1LTEyODFmZmQzOWU0NHgxNzkwMDc1MDczNjc1MDI2MDAw parts=12215--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.71s)22162026/09/22 11:04:33 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3003 objects_failed=02217=== NAME TestClientIntegration2218 client_integration_test.go:323: Objects in database after GC:2219 client_integration_test.go:323: Successfully deleted all objects with GC --force2220--- PASS: TestClientIntegration (4.38s)22212026/09/22 11:04:33 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22222026/09/22 11:04:34 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22232026/09/22 11:04:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22242026/09/22 11:04:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.511881999s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22252026/09/22 11:04:35 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-config22262026/09/22 11:04:35 WARN Rate limiter enabled after throttle name=s3-test rate=522272026/09/22 11:04:35 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2228=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2229 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102230 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002231--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.23s)22322026/09/22 11:04:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.842272ms 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 11:04:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.780579ms 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 11:04:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=864.230739ms 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 11:04:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.631835523s 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 11:04:39 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"22372026/09/22 11:04:39 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_closures22382026/09/22 11:04:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.139586ms 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 11:04:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=373.930975ms 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 11:04:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=832.357004ms 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 11:04:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.661771357s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2242--- PASS: TestClientErrorHandling (0.00s)2243 --- PASS: TestClientErrorHandling/InvalidStorePath (1.50s)2244 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.29s)2245 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.63s)2246PASS2247{"timestamp":"2026-09-22T11:04:42.32157Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63014","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)"}22482026-09-22 11:04:42.417 UTC [94395] LOG: received smart shutdown request22492026-09-22 11:04:42.418 UTC [94395] LOG: background worker "logical replication launcher" (PID 94405) exited with exit code 122502026-09-22 11:04:42.421 UTC [94400] LOG: shutting down22512026-09-22 11:04:42.421 UTC [94400] LOG: checkpoint starting: shutdown immediate22522026-09-22 11:04:43.496 UTC [94400] LOG: checkpoint complete: wrote 12970 buffers (79.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.719 s, sync=0.322 s, total=1.076 s; sync files=19072, longest=0.001 s, average=0.001 s; distance=264768 kB, estimate=264768 kB; lsn=0/11A1CF80, redo lsn=0/11A1CF8022532026-09-22 11:04:43.500 UTC [94395] LOG: database system is shut down2254Running OIDC tests...2255=== RUN TestAudienceForIssuer2256=== PAUSE TestAudienceForIssuer2257=== RUN TestGlobMatch2258=== PAUSE TestGlobMatch2259=== RUN TestValidateToken_ValidToken2260=== PAUSE TestValidateToken_ValidToken2261=== RUN TestValidateToken_WrongAudience2262=== PAUSE TestValidateToken_WrongAudience2263=== RUN TestValidateToken_Expired2264=== PAUSE TestValidateToken_Expired2265=== RUN TestValidateToken_BoundClaimsMismatch2266=== PAUSE TestValidateToken_BoundClaimsMismatch2267=== RUN TestValidateToken_BoundSubjectMismatch2268=== PAUSE TestValidateToken_BoundSubjectMismatch2269=== RUN TestValidateToken_MultipleProviders2270=== PAUSE TestValidateToken_MultipleProviders2271=== RUN TestValidateToken_NoMatchingProvider2272=== PAUSE TestValidateToken_NoMatchingProvider2273=== RUN TestValidateToken_KubernetesServiceAccount2274=== PAUSE TestValidateToken_KubernetesServiceAccount2275=== RUN TestNewValidator_KubernetesRequiresCA2276=== PAUSE TestNewValidator_KubernetesRequiresCA2277=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2278=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2279=== RUN TestPins_ReservedForMatchingRule2280=== PAUSE TestPins_ReservedForMatchingRule2281=== RUN TestPins_TopLevelShorthand2282=== PAUSE TestPins_TopLevelShorthand2283=== RUN TestPins_ConfigValidation2284=== PAUSE TestPins_ConfigValidation2285=== RUN TestScopes_LegacyProviderDefaultsToWrite2286=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2287=== RUN TestScopes_Rules2288=== PAUSE TestScopes_Rules2289=== RUN TestScopes_ConfigValidation2290=== PAUSE TestScopes_ConfigValidation2291=== CONT TestAudienceForIssuer2292--- PASS: TestAudienceForIssuer (0.00s)2293=== CONT TestValidateToken_BoundSubjectMismatch2294=== CONT TestValidateToken_MultipleProviders2295=== CONT TestPins_TopLevelShorthand2296=== CONT TestScopes_ConfigValidation2297=== CONT TestScopes_Rules2298=== CONT TestScopes_LegacyProviderDefaultsToWrite2299=== CONT TestPins_ConfigValidation2300=== CONT TestNewValidator_KubernetesRequiresCA2301=== CONT TestPins_ReservedForMatchingRule2302=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2303--- PASS: TestScopes_ConfigValidation (0.00s)2304=== CONT TestValidateToken_KubernetesServiceAccount2305--- PASS: TestPins_ConfigValidation (0.00s)2306=== CONT TestValidateToken_NoMatchingProvider23072026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63156/oidc2308--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.05s)2309=== CONT TestValidateToken_BoundClaimsMismatch23102026/09/22 11:04:44 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232311--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)2312=== CONT TestValidateToken_Expired23132026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63162/oidc2314--- PASS: TestPins_TopLevelShorthand (0.07s)2315=== CONT TestValidateToken_ValidToken23162026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63164/oidc2317--- PASS: TestValidateToken_Expired (0.02s)2318=== CONT TestGlobMatch2319=== RUN TestGlobMatch/foo_foo2320=== PAUSE TestGlobMatch/foo_foo2321=== RUN TestGlobMatch/foo_bar2322=== PAUSE TestGlobMatch/foo_bar2323=== RUN TestGlobMatch/*_2324=== PAUSE TestGlobMatch/*_2325=== RUN TestGlobMatch/*_anything2326=== PAUSE TestGlobMatch/*_anything2327=== RUN TestGlobMatch/foo*_foo2328=== PAUSE TestGlobMatch/foo*_foo2329=== RUN TestGlobMatch/foo*_foobar2330=== PAUSE TestGlobMatch/foo*_foobar2331=== RUN TestGlobMatch/foo*_bar2332=== PAUSE TestGlobMatch/foo*_bar2333=== RUN TestGlobMatch/*bar_bar2334=== PAUSE TestGlobMatch/*bar_bar2335=== RUN TestGlobMatch/*bar_foobar2336=== PAUSE TestGlobMatch/*bar_foobar2337=== RUN TestGlobMatch/*bar_foo2338=== PAUSE TestGlobMatch/*bar_foo2339=== RUN TestGlobMatch/foo*bar_foobar2340=== PAUSE TestGlobMatch/foo*bar_foobar2341=== RUN TestGlobMatch/foo*bar_foo123bar2342=== PAUSE TestGlobMatch/foo*bar_foo123bar2343=== RUN TestGlobMatch/foo*bar_foobarbaz2344=== PAUSE TestGlobMatch/foo*bar_foobarbaz2345=== RUN TestGlobMatch/*/*_foo/bar2346=== PAUSE TestGlobMatch/*/*_foo/bar2347=== RUN TestGlobMatch/*/*_foo2348=== PAUSE TestGlobMatch/*/*_foo2349=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2350=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2351=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02352=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02353=== RUN TestGlobMatch/refs/*/main_refs/heads/main2354=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2355=== RUN TestGlobMatch/fo?_foo2356=== PAUSE TestGlobMatch/fo?_foo2357=== RUN TestGlobMatch/fo?_fo2358=== PAUSE TestGlobMatch/fo?_fo2359=== RUN TestGlobMatch/fo?_fooo2360=== PAUSE TestGlobMatch/fo?_fooo2361=== RUN TestGlobMatch/?oo_foo2362=== PAUSE TestGlobMatch/?oo_foo2363=== RUN TestGlobMatch/?oo_boo2364=== PAUSE TestGlobMatch/?oo_boo2365=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2366=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2367=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2368=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2369=== CONT TestValidateToken_WrongAudience23702026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63166/oidc23712026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63168/oidc23722026/09/22 11:04:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63160/oidc23732026/09/22 11:04:44 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:63169/oidc2374--- PASS: TestPins_ReservedForMatchingRule (0.07s)2375=== CONT TestGlobMatch/foo_foo2376=== CONT TestGlobMatch/*/*_foo/bar2377=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2378=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2379=== CONT TestGlobMatch/?oo_boo2380=== CONT TestGlobMatch/?oo_foo2381=== CONT TestGlobMatch/fo?_fooo2382=== CONT TestGlobMatch/fo?_fo2383=== CONT TestGlobMatch/fo?_foo2384=== CONT TestGlobMatch/refs/*/main_refs/heads/main2385=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02386=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2387=== CONT TestGlobMatch/*/*_foo2388=== CONT TestGlobMatch/*bar_bar2389=== CONT TestGlobMatch/foo*bar_foobarbaz2390=== CONT TestGlobMatch/foo*bar_foo123bar2391=== CONT TestGlobMatch/foo*bar_foobar2392=== CONT TestGlobMatch/*bar_foo2393=== CONT TestGlobMatch/*bar_foobar2394=== CONT TestGlobMatch/foo*_foo2395=== CONT TestGlobMatch/foo*_bar2396=== CONT TestGlobMatch/foo*_foobar2397=== CONT TestGlobMatch/*_2398=== CONT TestGlobMatch/*_anything2399=== CONT TestGlobMatch/foo_bar2400--- PASS: TestGlobMatch (0.00s)2401 --- PASS: TestGlobMatch/foo_foo (0.00s)2402 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2403 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2404 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2405 --- PASS: TestGlobMatch/?oo_boo (0.00s)2406 --- PASS: TestGlobMatch/?oo_foo (0.00s)2407 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2408 --- PASS: TestGlobMatch/fo?_fo (0.00s)2409 --- PASS: TestGlobMatch/fo?_foo (0.00s)2410 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2411 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2412 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2413 --- PASS: TestGlobMatch/*/*_foo (0.00s)2414 --- PASS: TestGlobMatch/*bar_bar (0.00s)2415 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2416 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2417 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2418 --- PASS: TestGlobMatch/*bar_foo (0.00s)2419 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2420 --- PASS: TestGlobMatch/foo*_foo (0.00s)2421 --- PASS: TestGlobMatch/foo*_bar (0.00s)2422 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2423 --- PASS: TestGlobMatch/*_ (0.00s)2424 --- PASS: TestGlobMatch/*_anything (0.00s)2425 --- PASS: TestGlobMatch/foo_bar (0.00s)2426--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)2427--- PASS: TestValidateToken_MultipleProviders (0.08s)24282026/09/22 11:04:44 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:631732429--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)24302026/09/22 11:04:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63161/oidc2431--- PASS: TestValidateToken_NoMatchingProvider (0.12s)24322026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63177/oidc2433--- PASS: TestValidateToken_ValidToken (0.07s)24342026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63179/oidc2435--- PASS: TestValidateToken_WrongAudience (0.07s)24362026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63181/oidc2437--- PASS: TestScopes_Rules (0.15s)24382026/09/22 11:04:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63185/oidc2439--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)24402026/09/22 11:04:44 http: TLS handshake error from 127.0.0.1:63184: read tcp 127.0.0.1:63183->127.0.0.1:63184: use of closed network connection2441--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)2442PASS2443Running hook tests...2444=== RUN TestSendPathsEmpty2445=== PAUSE TestSendPathsEmpty2446=== RUN TestQueueEnqueueAndFetch2447=== PAUSE TestQueueEnqueueAndFetch2448=== RUN TestQueueDeduplication2449=== PAUSE TestQueueDeduplication2450=== RUN TestQueueRemove2451=== PAUSE TestQueueRemove2452=== RUN TestQueueFetchBatchLimit2453=== PAUSE TestQueueFetchBatchLimit2454=== RUN TestQueueRetryMovesToBack2455=== PAUSE TestQueueRetryMovesToBack2456=== RUN TestQueueFetchRemoveLifecycle2457=== PAUSE TestQueueFetchRemoveLifecycle2458=== RUN TestQueueConcurrentWriters2459=== PAUSE TestQueueConcurrentWriters2460=== RUN TestQueueRemoveLargeClosure2461=== PAUSE TestQueueRemoveLargeClosure2462=== RUN TestServerClientIntegration2463=== PAUSE TestServerClientIntegration2464=== RUN TestServerQueueError2465=== PAUSE TestServerQueueError2466=== RUN TestGetListenerSocketActivation2467 server_test.go:210: === RUN TestGetListenerSocketActivation2468 --- PASS: TestGetListenerSocketActivation (0.00s)2469 PASS2470 2471--- PASS: TestGetListenerSocketActivation (0.01s)2472=== RUN TestDrainIsolatesPoisonPath2473=== PAUSE TestDrainIsolatesPoisonPath2474=== RUN TestRunNotBlockedByPoisonHead2475=== PAUSE TestRunNotBlockedByPoisonHead2476=== RUN TestDrainGivesUpWhenServerDown2477=== PAUSE TestDrainGivesUpWhenServerDown2478=== RUN TestFailedPathPrunedByLaterClosure2479=== PAUSE TestFailedPathPrunedByLaterClosure2480=== RUN TestWorkerUploadsAndRemoves2481=== PAUSE TestWorkerUploadsAndRemoves2482=== RUN TestWorkerSkipsGCdPaths2483=== PAUSE TestWorkerSkipsGCdPaths2484=== RUN TestWorkerPrunesClosureDeps2485=== PAUSE TestWorkerPrunesClosureDeps2486=== RUN TestDrainTimeout2487=== PAUSE TestDrainTimeout2488=== CONT TestSendPathsEmpty2489=== CONT TestServerQueueError2490--- PASS: TestSendPathsEmpty (0.00s)2491=== CONT TestQueueFetchBatchLimit2492=== CONT TestQueueRetryMovesToBack2493=== CONT TestQueueDeduplication2494=== CONT TestWorkerUploadsAndRemoves2495=== CONT TestQueueRemove2496=== CONT TestQueueRemoveLargeClosure2497=== CONT TestWorkerSkipsGCdPaths2498=== CONT TestDrainGivesUpWhenServerDown2499=== CONT TestQueueConcurrentWriters25002026/09/22 11:04:44 ERROR Failed to queue paths error="permission denied" count=12501--- PASS: TestServerQueueError (0.00s)2502=== CONT TestQueueFetchRemoveLifecycle2503--- PASS: TestQueueFetchBatchLimit (0.01s)2504=== CONT TestFailedPathPrunedByLaterClosure25052026/09/22 11:04:44 INFO Uploading batch count=225062026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=225072026/09/22 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-94358-4077451566/TestDrainGivesUpWhenServerDown1258197193/002/a2508--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2509=== CONT TestServerClientIntegration2510--- PASS: TestQueueRetryMovesToBack (0.01s)25112026/09/22 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-94358-4077451566/TestDrainGivesUpWhenServerDown1258197193/002/b2512=== CONT TestDrainTimeout25132026/09/22 11:04:44 INFO Upload queue status pending=225142026/09/22 11:04:44 INFO Uploading batch count=225152026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=225162026/09/22 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-94358-4077451566/TestDrainGivesUpWhenServerDown1258197193/002/c25172026/09/22 11:04:44 INFO Uploading batch count=225182026/09/22 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-94358-4077451566/TestDrainGivesUpWhenServerDown1258197193/002/d25192026/09/22 11:04:44 INFO Upload queue status pending=22520--- PASS: TestQueueRemove (0.01s)2521=== CONT TestQueueEnqueueAndFetch25222026/09/22 11:04:44 INFO Uploading batch count=225232026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=225242026/09/22 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-94358-4077451566/TestDrainGivesUpWhenServerDown1258197193/002/e25252026/09/22 11:04:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-94358-4077451566/TestWorkerSkipsGCdPaths4163573645/002/nonexistent25262026/09/22 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-94358-4077451566/TestDrainGivesUpWhenServerDown1258197193/002/f2527--- PASS: TestServerClientIntegration (0.00s)2528=== CONT TestRunNotBlockedByPoisonHead25292026/09/22 11:04:44 INFO Uploading batch count=125302026/09/22 11:04:44 ERROR Drain finished with paths left in queue remaining=102531--- PASS: TestQueueDeduplication (0.01s)2532=== CONT TestDrainIsolatesPoisonPath25332026/09/22 11:04:44 INFO Uploading batch count=125342026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=12535--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2536=== CONT TestWorkerPrunesClosureDeps25372026/09/22 11:04:44 INFO Uploading batch count=125382026/09/22 11:04:44 INFO Uploading batch count=125392026/09/22 11:04:44 INFO Upload queue status pending=32540--- PASS: TestQueueEnqueueAndFetch (0.00s)25412026/09/22 11:04:44 INFO Uploading batch count=425422026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=425432026/09/22 11:04:44 INFO Uploading batch count=125442026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=125452026/09/22 11:04:44 INFO Uploading batch count=225462026/09/22 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-94358-4077451566/TestDrainIsolatesPoisonPath4071872744/002/bbb25472026/09/22 11:04:44 INFO Upload queue status pending=225482026/09/22 11:04:44 INFO Uploading batch count=125492026/09/22 11:04:44 INFO Uploading batch count=125502026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=125512026/09/22 11:04:44 INFO Uploading batch count=125522026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=12553--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)25542026/09/22 11:04:44 INFO Uploading batch count=125552026/09/22 11:04:44 ERROR Upload failed error="upload failed" count=125562026/09/22 11:04:44 ERROR Drain finished with paths left in queue remaining=12557--- PASS: TestDrainIsolatesPoisonPath (0.00s)2558--- PASS: TestWorkerUploadsAndRemoves (0.03s)2559--- PASS: TestWorkerSkipsGCdPaths (0.03s)2560--- PASS: TestWorkerPrunesClosureDeps (0.02s)2561--- PASS: TestQueueRemoveLargeClosure (0.05s)2562--- PASS: TestQueueConcurrentWriters (0.10s)25632026/09/22 11:04:44 ERROR Upload failed error="context deadline exceeded" count=225642026/09/22 11:04:44 ERROR Drain finished with paths left in queue remaining=42565--- PASS: TestDrainTimeout (0.21s)25662026/09/22 11:04:45 INFO Uploading batch count=125672026/09/22 11:04:45 INFO Uploading batch count=125682026/09/22 11:04:45 INFO Uploading batch count=125692026/09/22 11:04:45 ERROR Upload failed error="upload failed" count=125702026/09/22 11:04:45 INFO Uploading batch count=125712026/09/22 11:04:45 ERROR Upload failed error="upload failed" count=125722026/09/22 11:04:45 INFO Uploading batch count=125732026/09/22 11:04:45 ERROR Upload failed error="upload failed" count=125742026/09/22 11:04:45 INFO Uploading batch count=125752026/09/22 11:04:45 ERROR Upload failed error="upload failed" count=125762026/09/22 11:04:45 ERROR Drain finished with paths left in queue remaining=12577--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2578PASS