niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #353
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestPathInfoCACompatibility101=== RUN TestPathInfoCACompatibility/null_ca_field102=== PAUSE TestPathInfoCACompatibility/null_ca_field103=== CONT TestFileTokenReadsAndCaches104=== CONT TestScriptTokenEmptyCommand105--- PASS: TestScriptTokenEmptyCommand (0.00s)106=== CONT TestEncodeNixBase32WithRealHash107--- PASS: TestEncodeNixBase32WithRealHash (0.00s)108=== CONT TestStreamPushRequestLine109=== CONT TestScriptTokenScriptFails110=== CONT TestScriptTokenBadJSON111--- PASS: TestFileTokenReadsAndCaches (0.00s)112=== CONT TestShellSplit113--- PASS: TestShellSplit (0.00s)114=== CONT TestEncodeNixBase32115=== RUN TestEncodeNixBase32/test_string_hash116=== PAUSE TestEncodeNixBase32/test_string_hash117=== RUN TestEncodeNixBase32/empty_input118=== PAUSE TestEncodeNixBase32/empty_input119=== CONT TestStreamPushBatchesUnderLoad120=== CONT TestScriptTokenEmptyToken121=== CONT TestScriptTokenCachesUntilRefresh122=== CONT TestScriptTokenNoExpiryRerunsEveryCall123=== CONT TestFileTokenEmpty124=== CONT TestFileTokenMissing125=== CONT TestDumpPathSingleFile1262026/10/04 20:03:25 ERROR Upload failed error=boom count=1127=== CONT TestResolveStorePath128=== CONT TestStreamPushIsolatesFailures129=== CONT TestParsePathInfoJSONMultiplePaths130=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths131=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths132=== CONT TestStaticToken133=== CONT TestParsePathInfoJSON134=== CONT TestSetClientTLSErrors135=== CONT TestSetClientTLSDoesNotMutateDefaultTransport136=== CONT TestPathInfoHashCompatibility137=== CONT TestSetClientTLS138=== CONT TestGetStorePathHash139=== CONT TestClientSignaturesByStorePath140=== CONT TestConvertHashToNix32141=== CONT TestStreamPushReportsSignatures1422026/10/04 20:03:25 ERROR Upload failed error="bad path" count=3143=== RUN TestPathInfoCACompatibility/old_string_format_-_text144--- PASS: TestScriptTokenScriptFails (0.00s)145=== CONT TestDumpPathWriterError146=== CONT TestStreamPushReportsEveryPath147=== RUN TestParsePathInfoJSON/Nix_format148=== CONT TestDoWithRetry_BodyReplayedViaGetBody149=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== CONT TestShellSplitErrors151=== RUN TestGetStorePathHash/valid_store_path152=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== RUN TestConvertHashToNix32/SRI_format_to_Nix32154=== RUN TestSetClientTLSErrors/missing_cert_file155=== PAUSE TestSetClientTLSErrors/missing_cert_file156=== RUN TestSetClientTLSErrors/missing_key_file157=== PAUSE TestSetClientTLSErrors/missing_key_file158=== RUN TestSetClientTLSErrors/missing_ca_file159=== PAUSE TestSetClientTLSErrors/missing_ca_file160=== RUN TestSetClientTLSErrors/invalid_ca_file161=== PAUSE TestSetClientTLSErrors/invalid_ca_file162=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon164=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1652026/10/04 20:03:25 ERROR Upload failed error=boom count=1166=== CONT TestStreamPushGivesUpOnDeadServer167=== CONT TestFilterOversizedClosures168=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun169=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text170=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths171=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32172=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica173=== CONT TestUploadMultipart_SupersededByPeer174=== RUN TestFilterOversizedClosures/no_limit_keeps_everything175=== RUN TestUploadMultipart_SupersededByPeer/exists176=== PAUSE TestUploadMultipart_SupersededByPeer/exists177=== RUN TestUploadMultipart_SupersededByPeer/missing178=== PAUSE TestUploadMultipart_SupersededByPeer/missing1792026/10/04 20:03:25 WARN Rate limiter enabled after throttle name=server-test rate=5180=== CONT TestUploadMultipart_PartsInParallel181=== RUN TestConvertHashToNix32/already_Nix32_format182=== PAUSE TestConvertHashToNix32/already_Nix32_format183=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive184=== CONT TestRegisterUploadedObjectReusesConnections185=== CONT TestDumpPathMatchesNix186=== CONT TestCaseHackSuffix187=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon188=== CONT TestRateLimiterFeedback189=== CONT TestPartSizeForNAR190=== PAUSE TestGetStorePathHash/valid_store_path191--- PASS: TestFileTokenEmpty (0.00s)192=== PAUSE TestParsePathInfoJSON/Nix_format193=== RUN TestConvertHashToNix32/invalid_format1942026/10/04 20:03:25 ERROR Upload failed error="connection refused" count=20195=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1962026/10/04 20:03:25 ERROR Server seems unavailable, giving up on batch untried=17197=== RUN TestParsePathInfoJSON/Lix_format198=== PAUSE TestParsePathInfoJSON/Lix_format199=== RUN TestParsePathInfoJSON/empty_input200=== PAUSE TestParsePathInfoJSON/empty_input201=== RUN TestParsePathInfoJSON/whitespace_only202=== PAUSE TestParsePathInfoJSON/whitespace_only203=== RUN TestParsePathInfoJSON/invalid_JSON204=== PAUSE TestParsePathInfoJSON/invalid_JSON205=== PAUSE TestConvertHashToNix32/invalid_format206=== CONT TestEncodeNixBase32/test_string_hash207=== CONT TestSetClientTLSErrors/invalid_ca_file2082026/10/04 20:03:25 WARN Rate limiter enabled after throttle name=server-test rate=52092026/10/04 20:03:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:331352102026/10/04 20:03:25 INFO Garbage collection started2112026/10/04 20:03:25 INFO Garbage collection started212=== CONT TestSetClientTLSErrors/missing_ca_file213=== CONT TestEncodeNixBase32/empty_input214=== CONT TestSetClientTLSErrors/missing_key_file215=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths216=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths217=== RUN TestSetClientTLS/rejects_connection_without_client_cert218=== CONT TestSetClientTLSErrors/missing_cert_file219=== CONT TestUploadMultipart_SupersededByPeer/exists220=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert221=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA222=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA2232026/10/04 20:03:25 WARN Rate limiter backed off name=server-test rate=5224=== RUN TestSetClientTLS/preserves_debug_logging_transport2252026/10/04 20:03:25 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33135226=== CONT TestUploadMultipart_SupersededByPeer/missing227=== CONT TestParsePathInfoJSON/Nix_format228=== CONT TestConvertHashToNix32/SRI_format_to_Nix32229=== CONT TestParsePathInfoJSON/Lix_format230=== CONT TestParsePathInfoJSON/invalid_JSON231=== CONT TestParsePathInfoJSON/whitespace_only232=== CONT TestParsePathInfoJSON/empty_input233=== CONT TestConvertHashToNix32/invalid_format234=== RUN TestPartSizeForNAR/zero_stays_at_minimum235=== RUN TestGetStorePathHash/basename_without_hyphen_should_error236=== RUN TestRateLimiterFeedback/429_enables_limiter237=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI238--- PASS: TestFileTokenMissing (0.00s)239=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything2402026/10/04 20:03:25 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0241=== RUN TestPathInfoCACompatibility/new_structured_format_-_text242=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text243=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method244=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method245=== CONT TestPathInfoCACompatibility/null_ca_field246=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum247=== RUN TestPartSizeForNAR/small_stays_at_minimum248=== PAUSE TestPartSizeForNAR/small_stays_at_minimum249=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum250=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum251=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts252=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts253=== RUN TestPartSizeForNAR/1_TiB254=== PAUSE TestPartSizeForNAR/1_TiB255=== RUN TestPartSizeForNAR/5_TiB_S3_max_object256=== PAUSE TestSetClientTLS/preserves_debug_logging_transport257=== CONT TestSetClientTLS/rejects_connection_without_client_cert258=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI259=== CONT TestConvertHashToNix32/already_Nix32_format260=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512261=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped262=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped263=== RUN TestFilterOversizedClosures/all_closures_skipped264=== PAUSE TestFilterOversizedClosures/all_closures_skipped265=== CONT TestFilterOversizedClosures/no_limit_keeps_everything266--- PASS: TestStaticToken (0.00s)267--- PASS: TestClientSignaturesByStorePath (0.00s)268--- PASS: TestScriptTokenBadJSON (0.00s)269--- PASS: TestScriptTokenEmptyToken (0.00s)270--- PASS: TestDoServerRequestAttachesToken (0.01s)271=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object272=== RUN TestPartSizeForNAR/capped_at_5_GiB273=== PAUSE TestPartSizeForNAR/capped_at_5_GiB274=== CONT TestPartSizeForNAR/zero_stays_at_minimum275=== CONT TestFilterOversizedClosures/all_closures_skipped2762026/10/04 20:03:25 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=50277=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2782026/10/04 20:03:25 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=2000279--- PASS: TestStreamPushIsolatesFailures (0.00s)280--- PASS: TestShellSplitErrors (0.00s)281--- PASS: TestStreamPushReportsEveryPath (0.00s)282--- PASS: TestStreamPushReportsSignatures (0.00s)283--- PASS: TestResolveStorePath (0.01s)284--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)285=== CONT TestSetClientTLS/preserves_debug_logging_transport286=== CONT TestPathInfoCACompatibility/new_structured_format_-_text287=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method288=== PAUSE TestRateLimiterFeedback/429_enables_limiter289=== RUN TestRateLimiterFeedback/503_enables_limiter290=== PAUSE TestRateLimiterFeedback/503_enables_limiter291=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter292=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter293=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter294=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter295=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive296=== CONT TestRateLimiterFeedback/429_enables_limiter297=== CONT TestPartSizeForNAR/capped_at_5_GiB298=== CONT TestPartSizeForNAR/5_TiB_S3_max_object299=== CONT TestPartSizeForNAR/1_TiB300=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts301=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512302=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)303=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter304=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512305=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI306=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum307=== CONT TestRateLimiterFeedback/503_enables_limiter308=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3092026/10/04 20:03:25 WARN Rate limiter enabled after throttle name=server-test rate=53102026/10/04 20:03:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:41879311=== CONT TestPathInfoCACompatibility/old_string_format_-_text312--- PASS: TestStreamPushGivesUpOnDeadServer (0.02s)313=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3142026/10/04 20:03:25 WARN Rate limiter backed off name=server-test rate=5315--- PASS: TestEncodeNixBase32 (0.00s)316 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)317 --- PASS: TestEncodeNixBase32/empty_input (0.00s)318--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)319=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA320=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error3212026/10/04 20:03:25 WARN Rate limiter enabled after throttle name=server-test rate=5322=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error3232026/10/04 20:03:25 WARN Garbage collection finished on another replica; its statistics are not available here324=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error325=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error326=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error327=== CONT TestGetStorePathHash/valid_store_path3282026/10/04 20:03:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43775329--- PASS: TestDumpPathSingleFile (0.03s)330--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)331=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error332=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error333=== CONT TestGetStorePathHash/basename_without_hyphen_should_error334=== CONT TestPartSizeForNAR/small_stays_at_minimum335--- PASS: TestFilterOversizedClosures (0.03s)336 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)337 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)338 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3392026/10/04 20:03:25 WARN Rate limiter backed off name=server-test rate=5340--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)341 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)342 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)343--- PASS: TestPartSizeForNAR (0.00s)344 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)345 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)346 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)347 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)348 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)349 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)350 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)351--- PASS: TestPathInfoCACompatibility (0.03s)352 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)353 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)354 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)355 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)356 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)357--- PASS: TestParsePathInfoJSON (0.03s)358 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)359 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)360 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)361 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)362 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)363--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)364 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)365 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)366--- PASS: TestConvertHashToNix32 (0.03s)367 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)368 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)369 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)370--- PASS: TestRateLimiterFeedback (0.00s)371 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)374 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)375--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)376--- PASS: TestGetStorePathHash (0.03s)377 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)378 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)379 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)380 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)381--- PASS: TestPathInfoHashCompatibility (0.03s)382 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)383 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)384 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)385 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)386--- PASS: TestSetClientTLSErrors (0.00s)387 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)391--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)392--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3932026/10/04 20:03:25 http: TLS handshake error from 127.0.0.1:54334: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.03s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)398--- PASS: TestStreamPushRequestLine (0.06s)399--- PASS: TestCaseHackSuffix (0.03s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.08s)404--- PASS: TestUploadMultipart_PartsInParallel (0.64s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1361827759/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres1361827759/data -l logfile start434435/build/postgres1361827759:5432 - no response4362026-10-04 20:03:26.793 UTC [127] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-04 20:03:26.794 UTC [127] LOG: listening on Unix socket "/build/postgres1361827759/.s.PGSQL.5432"4382026-10-04 20:03:26.799 UTC [134] LOG: database system was shut down at 2026-10-04 20:03:26 UTC4392026-10-04 20:03:26.803 UTC [127] LOG: database system is ready to accept connections440/build/postgres1361827759:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/04 20:03:27 INFO lead: acquired remote=192.0.2.1:12344872026/10/04 20:03:28 INFO lead: released remote=192.0.2.1:12344882026/10/04 20:03:28 INFO lead: acquired remote=192.0.2.1:12344892026/10/04 20:03:29 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (2.33s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestLeadEndsWhenItsConnectionHangs4942026/10/04 20:03:29 INFO lead: acquired remote=192.0.2.1:12344952026-10-04 20:03:30.943 UTC [379] FATAL: terminating connection due to administrator command4962026/10/04 20:03:31 INFO lead: acquired remote=192.0.2.1:12344972026/10/04 20:03:32 WARN lead: lock connection lost error="timeout: context deadline exceeded"4982026/10/04 20:03:32 INFO lead: released remote=192.0.2.1:12344992026/10/04 20:03:32 INFO lead: released remote=192.0.2.1:1234500--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)501=== RUN TestGCAdvisoryLockBlocksConcurrentRun502=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun503=== RUN TestGCBugBareHashReferences504=== PAUSE TestGCBugBareHashReferences505=== RUN TestGCMetrics506=== PAUSE TestGCMetrics507=== RUN TestPushDedupSurvivesConcurrentGC508=== PAUSE TestPushDedupSurvivesConcurrentGC509=== RUN TestDeduplicatedObjectsRecordedAsPending510=== PAUSE TestDeduplicatedObjectsRecordedAsPending511=== RUN TestGCSweepSkipsPendingObjects512=== PAUSE TestGCSweepSkipsPendingObjects513=== RUN TestTombstonedObjectOfferedWithoutWaiting514=== PAUSE TestTombstonedObjectOfferedWithoutWaiting515=== RUN TestGCSweepDeliversEachKeyOnce516=== PAUSE TestGCSweepDeliversEachKeyOnce517=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection518=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection519=== RUN TestForceGCDuringPushOffersSweptObject520=== PAUSE TestForceGCDuringPushOffersSweptObject521=== RUN TestFailedS3DeleteKeepsTombstone522=== PAUSE TestFailedS3DeleteKeepsTombstone523=== RUN TestSweepSkipsRowsLockedByPush524=== PAUSE TestSweepSkipsRowsLockedByPush525=== RUN TestRegisterCompletedObjectNeedsPendingRow526=== PAUSE TestRegisterCompletedObjectNeedsPendingRow527=== RUN TestGetExistingObjectsLocksRows528=== PAUSE TestGetExistingObjectsLocksRows529=== RUN TestSweepRechecksPendingAfterLocking530=== PAUSE TestSweepRechecksPendingAfterLocking531=== RUN TestPushWaitsForSweepHoldingRow532=== PAUSE TestPushWaitsForSweepHoldingRow533=== RUN TestCommitRacingPendingCleanupKeepsObjects534=== PAUSE TestCommitRacingPendingCleanupKeepsObjects535=== RUN TestGCEndsOnShutdown536=== PAUSE TestGCEndsOnShutdown537=== RUN TestGCTaskStore_StartNew538=== PAUSE TestGCTaskStore_StartNew539=== RUN TestGCTaskStore_DeduplicateSameParams540=== PAUSE TestGCTaskStore_DeduplicateSameParams541=== RUN TestGCTaskStore_ConflictDifferentParams542=== PAUSE TestGCTaskStore_ConflictDifferentParams543=== RUN TestGCTaskStore_GetEmpty544=== PAUSE TestGCTaskStore_GetEmpty545=== RUN TestGCTaskStore_GetReturnsLatest546=== PAUSE TestGCTaskStore_GetReturnsLatest547=== RUN TestGCTaskStore_CompletedAllowsNewTask548=== PAUSE TestGCTaskStore_CompletedAllowsNewTask549=== RUN TestGCTaskStore_PhaseUpdates550=== PAUSE TestGCTaskStore_PhaseUpdates551=== RUN TestGCTaskStore_Fail552=== PAUSE TestGCTaskStore_Fail553=== RUN TestGracefulShutdownDrainsInflight554=== PAUSE TestGracefulShutdownDrainsInflight555=== RUN TestService_healthCheckHandler556=== PAUSE TestService_healthCheckHandler557=== RUN TestService_readinessHandler558=== PAUSE TestService_readinessHandler559=== RUN TestGenerateLandingPage560=== PAUSE TestGenerateLandingPage561=== RUN TestCacheConfigHandlerMaxNarSize562=== PAUSE TestCacheConfigHandlerMaxNarSize563=== RUN TestCreatePendingClosureRejectsOversizedNAR564=== PAUSE TestCreatePendingClosureRejectsOversizedNAR565=== RUN TestNARDeduplicationMetadataUploadBug566=== PAUSE TestNARDeduplicationMetadataUploadBug567=== RUN TestMetricsInventory568=== PAUSE TestMetricsInventory569=== RUN TestService_NativeMTLS570=== PAUSE TestService_NativeMTLS571=== RUN TestServerTLSConfig572=== PAUSE TestServerTLSConfig573=== RUN TestMultipartCleanup574=== PAUSE TestMultipartCleanup575=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded576=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded577=== RUN TestPendingCleanupUsesOneCutoff578=== PAUSE TestPendingCleanupUsesOneCutoff579=== RUN TestObjectStatsTrigger580=== PAUSE TestObjectStatsTrigger581=== RUN TestOrphanedObjectsGC582=== PAUSE TestOrphanedObjectsGC583=== RUN TestOrphanedObjectsGCStressTest584=== PAUSE TestOrphanedObjectsGCStressTest585=== RUN TestCreatePin_ReservedPins586=== PAUSE TestCreatePin_ReservedPins587=== RUN TestPresentReportsOnlyClosureRoots588=== PAUSE TestPresentReportsOnlyClosureRoots589=== RUN TestPresentNotReportedWhileGCDeletesClosure590=== PAUSE TestPresentNotReportedWhileGCDeletesClosure591=== RUN TestParseSingleRange592=== PAUSE TestParseSingleRange593=== RUN TestProxyHeadersOnlyTrustedOnSocket594=== PAUSE TestProxyHeadersOnlyTrustedOnSocket595=== RUN TestIsValidCachePath596=== PAUSE TestIsValidCachePath597=== RUN TestReadProxyNarinfo598=== PAUSE TestReadProxyNarinfo599=== RUN TestReadProxyNarinfoAlreadyDecompressed600=== PAUSE TestReadProxyNarinfoAlreadyDecompressed601=== RUN TestReadProxyNarStreaming602=== PAUSE TestReadProxyNarStreaming603=== RUN TestReadProxy404604=== PAUSE TestReadProxy404605=== RUN TestReadProxyInvalidPath606=== PAUSE TestReadProxyInvalidPath607=== RUN TestReadProxyHead608=== PAUSE TestReadProxyHead609=== RUN TestReadProxyOutlastsServerWriteTimeout610=== PAUSE TestReadProxyOutlastsServerWriteTimeout611=== RUN TestReadProxyConditionalGet612=== PAUSE TestReadProxyConditionalGet613=== RUN TestReadProxyRootRedirectsToIndexHTML614=== PAUSE TestReadProxyRootRedirectsToIndexHTML615=== RUN TestReadProxyDisabled616=== PAUSE TestReadProxyDisabled617=== RUN TestReadRedirectNar618=== PAUSE TestReadRedirectNar619=== RUN TestReadRedirectKeepsNarinfoProxied620=== PAUSE TestReadRedirectKeepsNarinfoProxied621=== RUN TestReadProxyRangeRequest622=== PAUSE TestReadProxyRangeRequest623=== RUN TestReadRedirectUsesPublicS3URL624=== PAUSE TestReadRedirectUsesPublicS3URL625=== RUN TestPush_OverlappingRootsStoreOneRowPerKey626=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey627=== RUN TestPush_CompleteCommitsEveryRoot628=== PAUSE TestPush_CompleteCommitsEveryRoot629=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit630=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit631=== RUN TestPush_RejectsBadRequests632=== PAUSE TestPush_RejectsBadRequests633=== RUN TestPush_SignsNarinfosOfItsPendingObjects634=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects635=== RUN TestRedundantMultipartUpload636=== PAUSE TestRedundantMultipartUpload637=== RUN TestCompleteMultipartUpload_ErrorButObjectExists638=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists639=== RUN TestCompletedNarNotReofferedAcrossClosures640=== PAUSE TestCompletedNarNotReofferedAcrossClosures641=== RUN TestPresignedUploadRegisteredBeforeCommit642=== PAUSE TestPresignedUploadRegisteredBeforeCommit643=== RUN TestService_Rustfstest644=== PAUSE TestService_Rustfstest645=== RUN TestParseSize646=== PAUSE TestParseSize647=== RUN TestSkippedUploadsHandler648=== PAUSE TestSkippedUploadsHandler649=== RUN TestSystemdListenerNotActivated650--- PASS: TestSystemdListenerNotActivated (0.00s)651=== RUN TestWatchdogBeatsWhenHealthy652--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)653=== RUN TestWatchdogSkipsWhenUnhealthy6542026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/04 20:03:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"664--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)665=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== RUN TestProxyWriteTimeout668=== PAUSE TestProxyWriteTimeout669=== RUN TestPendingClosureWriteTimeout670=== PAUSE TestPendingClosureWriteTimeout671=== RUN TestIsValidUploadKey672=== PAUSE TestIsValidUploadKey673=== RUN TestUploadHandlersRejectInvalidKeys674=== PAUSE TestUploadHandlersRejectInvalidKeys675=== RUN TestUploadHandlersRejectOversizedBody676=== PAUSE TestUploadHandlersRejectOversizedBody677=== RUN TestService_cleanupPendingClosuresHandler678=== PAUSE TestService_cleanupPendingClosuresHandler679=== RUN TestService_createPendingClosureHandler680=== PAUSE TestService_createPendingClosureHandler681=== RUN TestService_verifyS3Integrity682=== PAUSE TestService_verifyS3Integrity683=== RUN TestCompleteMultipartUnregistered684=== PAUSE TestCompleteMultipartUnregistered685=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT686=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT687=== CONT TestSkippedUploadsHandler688=== CONT TestService_AuthMiddleware689=== CONT TestParseSize690=== CONT TestUploadHandlersRejectOversizedBody691=== CONT TestService_Rustfstest692=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT6932026/10/04 20:03:32 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000694=== CONT TestPresignedUploadRegisteredBeforeCommit695=== CONT TestCompleteMultipartUnregistered696=== CONT TestCompletedNarNotReofferedAcrossClosures697=== CONT TestCompleteMultipartUpload_ErrorButObjectExists698=== CONT TestRedundantMultipartUpload699=== CONT TestService_verifyS3Integrity700=== CONT TestPush_SignsNarinfosOfItsPendingObjects701=== CONT TestService_createPendingClosureHandler702=== CONT TestPendingClosureWriteTimeout703=== RUN TestPendingClosureWriteTimeout/empty704=== CONT TestPush_RejectsBadRequests705=== CONT TestUploadHandlersRejectInvalidKeys706=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit707=== CONT TestIsValidUploadKey708=== CONT TestPush_CompleteCommitsEveryRoot709=== CONT TestProxyWriteTimeout710=== CONT TestPush_OverlappingRootsStoreOneRowPerKey711=== CONT TestService_cleanupPendingClosuresHandler712=== CONT TestReadRedirectUsesPublicS3URL713--- PASS: TestParseSize (0.00s)714=== CONT TestGCTaskStore_DeduplicateSameParams715=== PAUSE TestPendingClosureWriteTimeout/empty716=== RUN TestPendingClosureWriteTimeout/400_objects717=== RUN TestIsValidUploadKey/narinfo718=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info719--- PASS: TestSkippedUploadsHandler (0.01s)720=== CONT TestReadProxyRangeRequest721--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)722=== RUN TestProxyWriteTimeout/narinfo723=== PAUSE TestPendingClosureWriteTimeout/400_objects724=== RUN TestPendingClosureWriteTimeout/670k_objects725=== PAUSE TestPendingClosureWriteTimeout/670k_objects726=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline727=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline728=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info729=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal730=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal731=== CONT TestOrphanedObjectsGC732=== CONT TestGCTaskStore_StartNew733--- PASS: TestGCTaskStore_StartNew (0.00s)734=== CONT TestObjectStatsTrigger735=== PAUSE TestProxyWriteTimeout/narinfo736=== RUN TestProxyWriteTimeout/1_GiB_nar737=== PAUSE TestIsValidUploadKey/narinfo738=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key739=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key740=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key741=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key742=== PAUSE TestProxyWriteTimeout/1_GiB_nar743=== RUN TestProxyWriteTimeout/10_GiB_nar744=== PAUSE TestProxyWriteTimeout/10_GiB_nar745=== CONT TestGCEndsOnShutdown746=== RUN TestIsValidUploadKey/nar_zst747=== RUN TestProxyWriteTimeout/unknown_size748=== PAUSE TestProxyWriteTimeout/unknown_size749=== PAUSE TestIsValidUploadKey/nar_zst750=== CONT TestReadRedirectKeepsNarinfoProxied751=== RUN TestIsValidUploadKey/nar_xz752=== PAUSE TestIsValidUploadKey/nar_xz753=== RUN TestIsValidUploadKey/nar_plain754=== PAUSE TestIsValidUploadKey/nar_plain755=== RUN TestIsValidUploadKey/listing756=== PAUSE TestIsValidUploadKey/listing757=== RUN TestIsValidUploadKey/build_log758=== PAUSE TestIsValidUploadKey/build_log759=== RUN TestIsValidUploadKey/build_log_home-manager_file760=== PAUSE TestIsValidUploadKey/build_log_home-manager_file761=== RUN TestIsValidUploadKey/build_log_plus_in_name762=== PAUSE TestIsValidUploadKey/build_log_plus_in_name763=== RUN TestIsValidUploadKey/build_log_question_mark764=== PAUSE TestIsValidUploadKey/build_log_question_mark765=== RUN TestIsValidUploadKey/build_log_equals766=== PAUSE TestIsValidUploadKey/build_log_equals767=== RUN TestIsValidUploadKey/realisation768=== PAUSE TestIsValidUploadKey/realisation769=== RUN TestIsValidUploadKey/realisation_plus_in_output770=== PAUSE TestIsValidUploadKey/realisation_plus_in_output771=== RUN TestIsValidUploadKey/nix-cache-info772=== PAUSE TestIsValidUploadKey/nix-cache-info773=== RUN TestIsValidUploadKey/index.html774=== PAUSE TestIsValidUploadKey/index.html775=== RUN TestIsValidUploadKey/narinfo_key,_nar_type776=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type777=== RUN TestIsValidUploadKey/nar_key,_narinfo_type778=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type779=== RUN TestIsValidUploadKey/listing_key,_narinfo_type780=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type781=== RUN TestIsValidUploadKey/traversal782=== PAUSE TestIsValidUploadKey/traversal783=== RUN TestIsValidUploadKey/traversal_nar784=== PAUSE TestIsValidUploadKey/traversal_nar785=== RUN TestIsValidUploadKey/absolute786=== PAUSE TestIsValidUploadKey/absolute787=== RUN TestIsValidUploadKey/empty_key788=== PAUSE TestIsValidUploadKey/empty_key789=== RUN TestIsValidUploadKey/unknown_type790=== PAUSE TestIsValidUploadKey/unknown_type791=== CONT TestReadRedirectNar792=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure793=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure794=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart795=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart796=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts797=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts798=== CONT TestPushWaitsForSweepHoldingRow7992026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8002026/10/04 20:03:33 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8012026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8022026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures803--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.30s)804=== CONT TestPendingCleanupUsesOneCutoff8052026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8062026/10/04 20:03:33 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"807--- PASS: TestService_AuthMiddleware (0.32s)808=== CONT TestReadProxyDisabled809=== RUN TestPush_RejectsBadRequests/bad_root810=== PAUSE TestPush_RejectsBadRequests/bad_root811=== RUN TestPush_RejectsBadRequests/root_not_in_objects812=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects813=== RUN TestPush_RejectsBadRequests/no_roots814=== PAUSE TestPush_RejectsBadRequests/no_roots815=== RUN TestPush_RejectsBadRequests/no_objects816=== PAUSE TestPush_RejectsBadRequests/no_objects817=== CONT TestCommitRacingPendingCleanupKeepsObjects818--- PASS: TestService_Rustfstest (0.35s)819=== CONT TestReadProxyRootRedirectsToIndexHTML8202026/10/04 20:03:33 INFO Received push request method=POST path=/api/pushes8212026/10/04 20:03:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8222026/10/04 20:03:33 INFO Signed narinfos id=1 count=1823--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.38s)824=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8252026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures826--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)827=== CONT TestMultipartCleanup8282026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8292026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8322026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures833--- PASS: TestReadProxyRangeRequest (0.48s)834=== CONT TestServerTLSConfig835=== RUN TestServerTLSConfig/no_client_CA836=== PAUSE TestServerTLSConfig/no_client_CA837=== RUN TestServerTLSConfig/missing_CA_file838=== PAUSE TestServerTLSConfig/missing_CA_file839=== RUN TestServerTLSConfig/not_a_PEM_file840=== PAUSE TestServerTLSConfig/not_a_PEM_file841=== CONT TestService_NativeMTLS8422026/10/04 20:03:33 INFO Received push request method=POST path=/api/pushes8432026/10/04 20:03:33 INFO Received complete push request method=POST path=/api/pushes/1/complete8442026/10/04 20:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8452026/10/04 20:03:33 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst846--- PASS: TestCompleteMultipartUnregistered (0.51s)847=== CONT TestMetricsInventory8482026/10/04 20:03:33 INFO Received push request method=POST path=/api/pushes8492026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures8502026/10/04 20:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8512026/10/04 20:03: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=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LjhkOTgwZmQ3LTkwZTMtNDM4MS04ZmNiLTEwMDE2NzcwMTBjNngxNzkxMTQ0MjEzMzEwMzczMDY2852--- PASS: TestReadRedirectUsesPublicS3URL (0.56s)853=== CONT TestReadProxyConditionalGet8542026/10/04 20:03:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LjhkOTgwZmQ3LTkwZTMtNDM4MS04ZmNiLTEwMDE2NzcwMTBjNngxNzkxMTQ0MjEzMzEwMzczMDY2 parts=18552026/10/04 20:03:33 INFO Received push request method=POST path=/api/pushes856--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.57s)857=== CONT TestNARDeduplicationMetadataUploadBug8582026/10/04 20:03:33 INFO Aborted multipart uploads count=0 kept=08592026/10/04 20:03:33 WARN Force mode enabled - objects will be deleted immediately without grace period8602026/10/04 20:03:33 INFO Received complete push request method=POST path=/api/pushes/1/complete8612026/10/04 20:03:33 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=0862--- PASS: TestPush_CompleteCommitsEveryRoot (0.59s)863=== CONT TestReadProxyOutlastsServerWriteTimeout8642026/10/04 20:03:33 INFO Vacuumed table table=pending_closures865--- PASS: TestGCEndsOnShutdown (0.53s)866=== CONT TestCreatePendingClosureRejectsOversizedNAR8672026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures868--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)869=== CONT TestReadProxyHead8702026/10/04 20:03:33 INFO Vacuumed table table=pending_objects8712026/10/04 20:03:33 INFO Vacuumed table table=multipart_uploads8722026/10/04 20:03:33 INFO Vacuumed table table=closures8732026/10/04 20:03:33 INFO Vacuumed table table=objects8742026/10/04 20:03:33 INFO Received complete push request method=POST path=/api/pushes/2/complete875--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.61s)876=== CONT TestSweepRechecksPendingAfterLocking877--- PASS: TestObjectStatsTrigger (0.56s)878=== CONT TestResolveDBConnectionString879=== RUN TestResolveDBConnectionString/flag_wins880=== PAUSE TestResolveDBConnectionString/flag_wins881=== RUN TestResolveDBConnectionString/file_when_flag_empty882=== PAUSE TestResolveDBConnectionString/file_when_flag_empty883=== RUN TestResolveDBConnectionString/missing_file_is_an_error884=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error885=== RUN TestResolveDBConnectionString/PGHOST_allows_empty886=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty887=== RUN TestResolveDBConnectionString/nothing_configured888=== PAUSE TestResolveDBConnectionString/nothing_configured889=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock890--- PASS: TestReadRedirectKeepsNarinfoProxied (0.58s)891=== CONT TestCacheConfigHandlerMaxNarSize892--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)893=== CONT TestClientFallsBackToClosures8942026/10/04 20:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8952026/10/04 20:03:33 INFO Received push request method=POST path=/api/pushes8962026/10/04 20:03:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LjMwYjJiMWZiLTRmYmUtNGMzMy1iZDNlLTVmMjFhZTFiZmU2ZHgxNzkxMTQ0MjEzMDc3MDI1MTU1 parts=128972026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures898--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.62s)899=== CONT TestGetExistingObjectsLocksRows9002026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures901--- PASS: TestReadRedirectNar (0.62s)902=== CONT TestClientPushesUseOnePush9032026/10/04 20:03:33 INFO Received cleanup request method=DELETE path=/api/pending_closures9042026/10/04 20:03:33 INFO Aborted multipart uploads count=0 kept=09052026/10/04 20:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9062026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/04 20:03:33 INFO Received cleanup request method=DELETE path=/api/pending_closures9082026/10/04 20:03:33 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LmJjM2Y5OGQ4LTFiZjEtNGViNi04Y2E2LTBhOWQ0MjM3ODhmNHgxNzkxMTQ0MjEzMjA4NTY1NDAy parts=109092026/10/04 20:03:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9102026/10/04 20:03:33 INFO Aborted multipart uploads count=1 kept=09112026/10/04 20:03:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9122026-10-04 20:03:33.520 UTC [466] ERROR: Closure does not exist: id=19132026-10-04 20:03:33.520 UTC [466] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9142026-10-04 20:03:33.520 UTC [466] STATEMENT: -- name: CommitPendingClosure :exec915 SELECT commit_pending_closure($1::bigint)916 9172026/10/04 20:03:33 INFO Completed upload id=1918--- PASS: TestService_cleanupPendingClosuresHandler (0.67s)919=== CONT TestRegisterCompletedObjectNeedsPendingRow9202026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9212026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9222026/10/04 20:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9232026/10/04 20:03:33 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9242026/10/04 20:03:33 WARN Found objects in DB but missing from S3, will re-upload count=1925--- PASS: TestService_verifyS3Integrity (0.76s)926=== CONT TestPinProtectsFromGC9272026/10/04 20:03:33 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LjdjOGQ5NzQ2LTk1NzktNDhiNi1hOGE3LTc1OTA0YTFmYTQyOHgxNzkxMTQ0MjEzMjI5Nzk1MTUw parts=109282026/10/04 20:03:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9292026/10/04 20:03:33 INFO Completed upload id=19302026/10/04 20:03:33 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009312026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9322026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9332026/10/04 20:03:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures9342026/10/04 20:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9352026/10/04 20:03:33 INFO Aborted multipart uploads count=0 kept=09362026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9372026/10/04 20:03:33 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LmE3ODg2NDYwLWM5M2UtNDQzNi1iMjEyLTFjOGQyZmIyYTI5ZHgxNzkxMTQ0MjEzMTg0MzM1Nzg3 parts=129382026/10/04 20:03:33 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09392026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9402026/10/04 20:03:33 INFO Vacuumed table table=pending_closures941--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.81s)942=== CONT TestSweepSkipsRowsLockedByPush9432026/10/04 20:03:33 INFO Vacuumed table table=pending_objects9442026/10/04 20:03:33 INFO Vacuumed table table=multipart_uploads9452026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9462026/10/04 20:03:33 INFO Vacuumed table table=closures9472026/10/04 20:03:33 INFO Vacuumed table table=objects9482026/10/04 20:03:33 INFO Received cleanup request method=DELETE path=/api/pending_closures949--- PASS: TestReadProxyDisabled (0.51s)950=== CONT TestClientSharedPathCommittedMidPush9512026/10/04 20:03:33 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000952--- PASS: TestService_createPendingClosureHandler (0.84s)953=== CONT TestGenerateLandingPage954--- PASS: TestGenerateLandingPage (0.00s)955=== CONT TestFailedS3DeleteKeepsTombstone956--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.53s)957=== CONT TestClientWithDependencies9582026/10/04 20:03:33 INFO Aborted multipart uploads count=0 kept=09592026/10/04 20:03:33 WARN Force mode enabled - objects will be deleted immediately without grace period9602026/10/04 20:03:33 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=09612026/10/04 20:03:33 INFO Vacuumed table table=pending_closures9622026/10/04 20:03:33 INFO Vacuumed table table=pending_objects9632026/10/04 20:03:33 INFO Vacuumed table table=multipart_uploads9642026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9652026/10/04 20:03:33 INFO Vacuumed table table=closures9662026/10/04 20:03:33 INFO Vacuumed table table=objects967--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.57s)968=== CONT TestService_readinessHandler969--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.53s)970=== CONT TestForceGCDuringPushOffersSweptObject971=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows972=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows973=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check974=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check975=== CONT TestReadProxyInvalidPath9762026/10/04 20:03:33 INFO Received uploads request method=POST path=/api/pending_closures9772026/10/04 20:03:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9782026/10/04 20:03:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"979--- PASS: TestService_NativeMTLS (0.46s)980=== CONT TestService_healthCheckHandler981--- PASS: TestMetricsInventory (0.46s)982=== CONT TestClientMultipleUploads983--- PASS: TestReadProxyConditionalGet (0.45s)984=== CONT TestGracefulShutdownDrainsInflight9852026/10/04 20:03:33 INFO Starting HTTP server address=127.0.0.1:336499862026/10/04 20:03:33 INFO Shutdown signal received, draining in-flight requests timeout=10s987=== NAME TestNARDeduplicationMetadataUploadBug988 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1182723381/001/store/fwrazhkbsdpi6p2v0r0s7ib4d83v5psf-file1.txt9892026/10/04 20:03:33 INFO Received cleanup request method=DELETE path=/api/pending_closures9902026/10/04 20:03:33 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket32/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9912026/10/04 20:03:33 INFO Aborted multipart uploads count=0 kept=19922026/10/04 20:03:33 INFO Received cleanup request method=DELETE path=/api/pending_closures9932026/10/04 20:03:33 INFO Aborted multipart uploads count=1 kept=0994--- PASS: TestMultipartCleanup (0.65s)995=== CONT TestClientIntegration996--- PASS: TestReadProxyHead (0.44s)997=== CONT TestReadProxy404998=== NAME TestOrphanedObjectsGC999 orphaned_objects_gc_test.go:290: GC Test Summary:1000 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1001 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1002 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1003 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1004 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1005--- PASS: TestOrphanedObjectsGC (0.98s)1006=== CONT TestClientErrorHandling1007=== RUN TestClientErrorHandling/InvalidStorePath1008=== PAUSE TestClientErrorHandling/InvalidStorePath1009=== RUN TestClientErrorHandling/InvalidAuthToken1010=== PAUSE TestClientErrorHandling/InvalidAuthToken1011=== RUN TestClientErrorHandling/ServerNotAvailable1012=== PAUSE TestClientErrorHandling/ServerNotAvailable1013=== CONT TestGCTaskStore_Fail1014--- PASS: TestGCTaskStore_Fail (0.00s)1015=== CONT TestClientCADerivations10162026/10/04 20:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10172026/10/04 20:03:33 INFO Aborted multipart uploads count=0 kept=01018--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1019=== CONT TestGCTaskStore_PhaseUpdates1020--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1021=== CONT TestParseSingleRange1022=== RUN TestParseSingleRange/none1023=== PAUSE TestParseSingleRange/none1024=== RUN TestParseSingleRange/unknown_unit1025=== PAUSE TestParseSingleRange/unknown_unit1026=== RUN TestParseSingleRange/multi-range_ignored1027=== PAUSE TestParseSingleRange/multi-range_ignored1028=== RUN TestParseSingleRange/malformed_no_dash1029=== PAUSE TestParseSingleRange/malformed_no_dash1030=== RUN TestParseSingleRange/malformed_both_empty1031=== PAUSE TestParseSingleRange/malformed_both_empty1032=== RUN TestParseSingleRange/malformed_end_before_start1033=== PAUSE TestParseSingleRange/malformed_end_before_start1034=== RUN TestParseSingleRange/closed1035=== PAUSE TestParseSingleRange/closed1036=== RUN TestParseSingleRange/open-ended1037=== PAUSE TestParseSingleRange/open-ended1038=== RUN TestParseSingleRange/end_clamped_to_size1039=== PAUSE TestParseSingleRange/end_clamped_to_size1040=== RUN TestParseSingleRange/suffix1041=== PAUSE TestParseSingleRange/suffix1042=== RUN TestParseSingleRange/suffix_exceeds_size1043=== PAUSE TestParseSingleRange/suffix_exceeds_size1044=== RUN TestParseSingleRange/single_byte1045=== PAUSE TestParseSingleRange/single_byte1046=== RUN TestParseSingleRange/start_past_EOF1047=== PAUSE TestParseSingleRange/start_past_EOF1048=== RUN TestParseSingleRange/start_far_past_EOF1049=== PAUSE TestParseSingleRange/start_far_past_EOF1050=== CONT TestCacheStatsHandler10512026/10/04 20:03:33 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LmM1YTkxZDc3LWMyMTUtNDUyZC04NTAzLTIzOTY3N2IyZTUyM3gxNzkxMTQ0MjEzNDc2NjIyMTIx error="Get \"http://127.0.0.1:1/bucket4/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10522026/10/04 20:03:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzUzYTBhNTctMGRiZi00NGVlLTk3YjYtOGI5OGVhZjk4YjQ2LjYxOWJlZTBmLTE1ODQtNDQ4OC04MGJjLWY4ZmUwZGMxMDIyN3gxNzkxMTQ0MjEzNDY4NDk3MTI5 parts=1210532026/10/04 20:03:33 WARN Force mode enabled - objects will be deleted immediately without grace period10542026/10/04 20:03:33 INFO Received cleanup request method=DELETE path=/api/pending_closures10552026/10/04 20:03:33 INFO Aborted multipart uploads count=1 kept=01056--- PASS: TestRedundantMultipartUpload (1.10s)1057=== CONT TestGCTaskStore_CompletedAllowsNewTask1058--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1059=== CONT TestPresentNotReportedWhileGCDeletesClosure10602026/10/04 20:03:33 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=010612026/10/04 20:03:33 INFO Vacuumed table table=pending_closures10622026/10/04 20:03:33 INFO Vacuumed table table=pending_objects10632026/10/04 20:03:33 INFO Vacuumed table table=multipart_uploads10642026/10/04 20:03:33 INFO Vacuumed table table=closures10652026/10/04 20:03:33 INFO Received push request method=POST path=/api/pushes10662026/10/04 20:03:33 INFO Vacuumed table table=objects1067--- PASS: TestSweepRechecksPendingAfterLocking (0.49s)1068=== CONT TestCacheConfigHandler1069=== RUN TestCacheConfigHandler/full_config,_no_issuer1070=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1071=== RUN TestCacheConfigHandler/no_cache_url_configured1072=== PAUSE TestCacheConfigHandler/no_cache_url_configured1073=== RUN TestCacheConfigHandler/no_signing_keys1074=== PAUSE TestCacheConfigHandler/no_signing_keys1075=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1076=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1077=== CONT TestGCTaskStore_GetReturnsLatest1078--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1079=== CONT TestProxyHeadersOnlyTrustedOnSocket10802026/10/04 20:03:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10812026/10/04 20:03:33 INFO Uploading fwrazhkbsdpi6p2v0r0s7ib4d83v5psf-file1.txt (160B)10822026/10/04 20:03:33 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10832026/10/04 20:03:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10842026/10/04 20:03:33 WARN Failed to register uploaded object key=fwrazhkbsdpi6p2v0r0s7ib4d83v5psf.ls error="server returned 404: 404 page not found\n"10852026/10/04 20:03:33 INFO Signed narinfos id=1 count=110862026/10/04 20:03:33 INFO Uploading 1 narinfos10872026/10/04 20:03:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10882026/10/04 20:03:33 WARN Failed to register uploaded object key=fwrazhkbsdpi6p2v0r0s7ib4d83v5psf.narinfo error="server returned 404: 404 page not found\n"10892026/10/04 20:03:33 INFO Upload complete. (66ms)1090=== NAME TestNARDeduplicationMetadataUploadBug1091 metadata_upload_test.go:54: Retrieved narinfo from S3:1092 StorePath: /build/TestNARDeduplicationMetadataUploadBug1182723381/001/store/fwrazhkbsdpi6p2v0r0s7ib4d83v5psf-file1.txt1093 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1094 Compression: zstd1095 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1096 NarSize: 1601097 References: 1098 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1099 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1100 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1101 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1102--- PASS: TestGetExistingObjectsLocksRows (0.45s)1103=== CONT TestService_ReadScope_PublicByDefault1104=== NAME TestNARDeduplicationMetadataUploadBug1105 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1182723381/001/store/ggpmv9hmbq89myknj8x5y9a7a1sdf4r3-file2.txt1106--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.43s)1107=== CONT TestService_RequireScope_OIDC11082026/10/04 20:03:34 INFO Aborted multipart uploads count=0 kept=011092026/10/04 20:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period11102026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes11112026/10/04 20:03:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11122026/10/04 20:03:34 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011132026/10/04 20:03:34 INFO Vacuumed table table=pending_closures11142026/10/04 20:03:34 INFO Vacuumed table table=pending_objects11152026/10/04 20:03:34 INFO Vacuumed table table=multipart_uploads11162026/10/04 20:03:34 INFO Vacuumed table table=closures11172026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11182026/10/04 20:03:34 INFO Vacuumed table table=objects11192026/10/04 20:03:34 INFO Signed narinfos id=2 count=111202026/10/04 20:03:34 WARN Failed to register uploaded object key=ggpmv9hmbq89myknj8x5y9a7a1sdf4r3.ls error="server returned 404: 404 page not found\n"11212026/10/04 20:03:34 INFO Uploading 1 narinfos11222026/10/04 20:03:34 INFO Aborted multipart uploads count=0 kept=011232026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/2/complete11242026/10/04 20:03:34 WARN Failed to register uploaded object key=ggpmv9hmbq89myknj8x5y9a7a1sdf4r3.narinfo error="server returned 404: 404 page not found\n"11252026/10/04 20:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period11262026/10/04 20:03:34 INFO Upload complete. (52ms)1127=== NAME TestNARDeduplicationMetadataUploadBug1128 metadata_upload_test.go:76: Retrieved narinfo from S3:1129 StorePath: /build/TestNARDeduplicationMetadataUploadBug1182723381/001/store/ggpmv9hmbq89myknj8x5y9a7a1sdf4r3-file2.txt1130 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1131 Compression: zstd1132 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1133 NarSize: 1601134 References: 1135 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11362026/10/04 20:03:34 INFO Received uploads request method=POST path=/api/pending_closures1137 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1138 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1139 {"version":1,"root":{"type":"regular","size":44}}1140--- PASS: TestNARDeduplicationMetadataUploadBug (0.69s)1141=== CONT TestPresentReportsOnlyClosureRoots11422026/10/04 20:03:34 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=011432026/10/04 20:03:34 INFO Vacuumed table table=pending_closures11442026/10/04 20:03:34 INFO Vacuumed table table=pending_objects11452026/10/04 20:03:34 INFO Vacuumed table table=multipart_uploads11462026/10/04 20:03:34 INFO Vacuumed table table=closures11472026/10/04 20:03:34 INFO Vacuumed table table=objects1148--- PASS: TestSweepSkipsRowsLockedByPush (0.47s)1149=== CONT TestService_AuthMiddleware_OIDC1150=== NAME TestPinProtectsFromGC1151 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC25062778/001/store/jd32m1hvcfawf42d1s57s0mm75sn7v6m-pinned-file.txt1152 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC25062778/001/store/v2gcdxgmsv7i353vhjj3haim07r5xf6v-unpinned-file.txt1153--- PASS: TestService_ReadScope_PublicByDefault (0.14s)1154=== CONT TestReadProxyNarStreaming1155--- PASS: TestPushWaitsForSweepHoldingRow (1.12s)1156=== CONT TestService_ReadAuthMiddleware11572026/10/04 20:03:34 INFO Received uploads request method=POST path=/api/pending_closures11582026/10/04 20:03:34 INFO Received uploads request method=POST path=/api/pending_closures11592026/10/04 20:03:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11602026/10/04 20:03:34 INFO Uploading vgx7ivkdm0d3302q22imq577rwgnaxiq-shared-dep (136B)11612026/10/04 20:03:34 INFO Uploading v3f1f9i46zm4anjxn1q3p7ww9zss8202-a (216B)11622026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/02bp7ksgg7rkrrnzyyzpvjranxpc18rcia68nanh5da8sqyrpa5f.nar.zst error="server returned 404: 404 page not found\n"11632026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11642026/10/04 20:03:34 WARN Failed to register uploaded object key=v3f1f9i46zm4anjxn1q3p7ww9zss8202.ls error="server returned 404: 404 page not found\n"11652026/10/04 20:03:34 WARN Failed to register uploaded object key=vgx7ivkdm0d3302q22imq577rwgnaxiq.ls error="server returned 404: 404 page not found\n"11662026/10/04 20:03:34 WARN Failed to register uploaded object key=k6rrnk9mhaxv9fq4gz4gqiip5cdxkx8v.ls error="server returned 404: 404 page not found\n"11672026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11682026/10/04 20:03:34 INFO Signed narinfos id=1 count=211692026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11702026/10/04 20:03:34 INFO Signed narinfos id=2 count=211712026/10/04 20:03:34 INFO Uploading 4 narinfos11722026/10/04 20:03:34 WARN Failed to register uploaded object key=vgx7ivkdm0d3302q22imq577rwgnaxiq.narinfo error="server returned 404: 404 page not found\n"11732026/10/04 20:03:34 WARN Failed to register uploaded object key=k6rrnk9mhaxv9fq4gz4gqiip5cdxkx8v.narinfo error="server returned 404: 404 page not found\n"11742026/10/04 20:03:34 WARN Failed to register uploaded object key=v3f1f9i46zm4anjxn1q3p7ww9zss8202.narinfo error="server returned 404: 404 page not found\n"11752026/10/04 20:03:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11762026/10/04 20:03:34 WARN Failed to register uploaded object key=vgx7ivkdm0d3302q22imq577rwgnaxiq.narinfo error="server returned 404: 404 page not found\n"11772026/10/04 20:03:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34815/oidc11782026/10/04 20:03:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44469/oidc11792026/10/04 20:03:34 INFO Completed upload id=111802026/10/04 20:03:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11812026/10/04 20:03:34 INFO Completed upload id=211822026/10/04 20:03:34 INFO Upload complete. (382ms)11832026/10/04 20:03:34 INFO Aborted multipart uploads count=0 kept=01184=== NAME TestClientFallsBackToClosures1185 client_pushes_test.go:112: Retrieved narinfo from S3:1186 StorePath: /build/TestClientFallsBackToClosures1528213795/001/store/vgx7ivkdm0d3302q22imq577rwgnaxiq-shared-dep1187 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1188 Compression: zstd1189 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821190 NarSize: 1361191 References: 1192 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11932026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes11942026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes1195 client_pushes_test.go:112: Retrieved narinfo from S3:1196 StorePath: /build/TestClientFallsBackToClosures1528213795/001/store/v3f1f9i46zm4anjxn1q3p7ww9zss8202-a1197 URL: nar/02bp7ksgg7rkrrnzyyzpvjranxpc18rcia68nanh5da8sqyrpa5f.nar.zst1198 Compression: zstd1199 NarHash: sha256:02bp7ksgg7rkrrnzyyzpvjranxpc18rcia68nanh5da8sqyrpa5f1200 NarSize: 2161201 References: /build/TestClientFallsBackToClosures1528213795/001/store/vgx7ivkdm0d3302q22imq577rwgnaxiq-shared-dep1202 CA: text:sha256:0qn84dy41m6r11k0ydyzrplkw3hxscb9l6v6bashv1irhm58p0zy1203 client_pushes_test.go:112: Retrieved narinfo from S3:1204 StorePath: /build/TestClientFallsBackToClosures1528213795/001/store/k6rrnk9mhaxv9fq4gz4gqiip5cdxkx8v-b1205 URL: nar/02bp7ksgg7rkrrnzyyzpvjranxpc18rcia68nanh5da8sqyrpa5f.nar.zst1206 Compression: zstd1207 NarHash: sha256:02bp7ksgg7rkrrnzyyzpvjranxpc18rcia68nanh5da8sqyrpa5f1208 NarSize: 2161209 References: /build/TestClientFallsBackToClosures1528213795/001/store/vgx7ivkdm0d3302q22imq577rwgnaxiq-shared-dep1210 CA: text:sha256:0qn84dy41m6r11k0ydyzrplkw3hxscb9l6v6bashv1irhm58p0zy12112026/10/04 20:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period12122026/10/04 20:03:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12132026/10/04 20:03:34 INFO Uploading jd32m1hvcfawf42d1s57s0mm75sn7v6m-pinned-file.txt (128B)12142026/10/04 20:03:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12152026/10/04 20:03:34 INFO Uploading jssb7vw5infql6168kwk5qywjygp62bn-a (216B)12162026/10/04 20:03:34 INFO Uploading hxm8q5gj69ki91kz9w19k5as2h7plvba-shared-dep (136B)1217--- PASS: TestClientFallsBackToClosures (0.99s)1218=== CONT TestReadProxyNarinfoAlreadyDecompressed12192026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12202026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12212026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12222026/10/04 20:03:34 WARN Failed to register uploaded object key=6r3891yxjcl1j0agdz5g7nnh6gwz2mdi.ls error="server returned 404: 404 page not found\n"12232026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12242026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/0l2h2s2p4xg268l4rprpc8j06l7n85zbcfqfm36pkidn6mix92ki.nar.zst error="server returned 404: 404 page not found\n"12252026/10/04 20:03:34 WARN Failed to register uploaded object key=jssb7vw5infql6168kwk5qywjygp62bn.ls error="server returned 404: 404 page not found\n"12262026/10/04 20:03:34 WARN Failed to register uploaded object key=jd32m1hvcfawf42d1s57s0mm75sn7v6m.ls error="server returned 404: 404 page not found\n"12272026/10/04 20:03:34 WARN Failed to register uploaded object key=hxm8q5gj69ki91kz9w19k5as2h7plvba.ls error="server returned 404: 404 page not found\n"12282026/10/04 20:03:34 INFO Signed narinfos id=1 count=312292026/10/04 20:03:34 INFO Signed narinfos id=1 count=112302026/10/04 20:03:34 INFO Uploading 3 narinfos12312026/10/04 20:03:34 INFO Uploading 1 narinfos12322026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete12332026/10/04 20:03:34 WARN Failed to register uploaded object key=jd32m1hvcfawf42d1s57s0mm75sn7v6m.narinfo error="server returned 404: 404 page not found\n"12342026/10/04 20:03:34 WARN Failed to register uploaded object key=hxm8q5gj69ki91kz9w19k5as2h7plvba.narinfo error="server returned 404: 404 page not found\n"12352026/10/04 20:03:34 WARN Failed to register uploaded object key=6r3891yxjcl1j0agdz5g7nnh6gwz2mdi.narinfo error="server returned 404: 404 page not found\n"12362026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete12372026/10/04 20:03:34 WARN Failed to register uploaded object key=jssb7vw5infql6168kwk5qywjygp62bn.narinfo error="server returned 404: 404 page not found\n"12382026/10/04 20:03:34 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12392026/10/04 20:03:34 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1240--- PASS: TestFailedS3DeleteKeepsTombstone (0.83s)1241=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12422026/10/04 20:03:34 WARN readiness check failed error="closed pool"1243--- PASS: TestService_readinessHandler (0.78s)1244=== CONT TestCreatePin_ReservedPins12452026/10/04 20:03:34 INFO Upload complete. (388ms)12462026/10/04 20:03:34 INFO Upload complete. (382ms)1247=== NAME TestClientPushesUseOnePush1248 client_pushes_test.go:97: Retrieved narinfo from S3:1249 StorePath: /build/TestClientPushesUseOnePush3816715668/001/store/hxm8q5gj69ki91kz9w19k5as2h7plvba-shared-dep1250 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1251 Compression: zstd1252 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821253 NarSize: 1361254 References: 1255 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1256 client_pushes_test.go:97: Retrieved narinfo from S3:1257 StorePath: /build/TestClientPushesUseOnePush3816715668/001/store/jssb7vw5infql6168kwk5qywjygp62bn-a1258 URL: nar/0l2h2s2p4xg268l4rprpc8j06l7n85zbcfqfm36pkidn6mix92ki.nar.zst1259 Compression: zstd1260 NarHash: sha256:0l2h2s2p4xg268l4rprpc8j06l7n85zbcfqfm36pkidn6mix92ki1261 NarSize: 2161262 References: /build/TestClientPushesUseOnePush3816715668/001/store/hxm8q5gj69ki91kz9w19k5as2h7plvba-shared-dep1263 CA: text:sha256:02lga3spvkpsgp2vwync84ypbxbg0zrgly5qz71hq3ss49f2by9s1264 client_pushes_test.go:97: Retrieved narinfo from S3:1265 StorePath: /build/TestClientPushesUseOnePush3816715668/001/store/6r3891yxjcl1j0agdz5g7nnh6gwz2mdi-b1266 URL: nar/0l2h2s2p4xg268l4rprpc8j06l7n85zbcfqfm36pkidn6mix92ki.nar.zst1267 Compression: zstd1268 NarHash: sha256:0l2h2s2p4xg268l4rprpc8j06l7n85zbcfqfm36pkidn6mix92ki1269 NarSize: 2161270 References: /build/TestClientPushesUseOnePush3816715668/001/store/hxm8q5gj69ki91kz9w19k5as2h7plvba-shared-dep1271 CA: text:sha256:02lga3spvkpsgp2vwync84ypbxbg0zrgly5qz71hq3ss49f2by9s1272--- PASS: TestClientPushesUseOnePush (0.99s)1273=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1274=== NAME TestClientWithDependencies1275 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3144386950/001/store/68pmlbkd8713qkrsp7gy496ywnl38r2j-test-script12762026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes1277--- PASS: TestReadProxyInvalidPath (0.81s)1278=== CONT TestReadProxyNarinfo12792026/10/04 20:03:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33415/oidc1280=== NAME TestClientWithDependencies1281 client_integration_test.go:615: Found 1 dependencies (including self)12822026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes12832026/10/04 20:03:34 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12842026/10/04 20:03:34 INFO Uploading 9yfya3if7aj5k6971nn1y7pnybz913xi-top (224B)12852026/10/04 20:03:34 INFO Uploading a8r6kgrlnnha5hvpqcpy8krjzq8br9an-shared-dep (136B)12862026/10/04 20:03:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12872026/10/04 20:03:34 INFO Uploading v2gcdxgmsv7i353vhjj3haim07r5xf6v-unpinned-file.txt (128B)12882026/10/04 20:03:34 WARN Failed to register uploaded object key=v2gcdxgmsv7i353vhjj3haim07r5xf6v.ls error="server returned 404: 404 page not found\n"12892026/10/04 20:03:34 WARN Failed to register uploaded object key=a8r6kgrlnnha5hvpqcpy8krjzq8br9an.ls error="server returned 404: 404 page not found\n"12902026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12912026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12922026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/0zzwr5iqhklymfjw16bi4bsf5hscja2wgwgy5fmjyffnpm89xjs8.nar.zst error="server returned 404: 404 page not found\n"12932026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12942026/10/04 20:03:34 WARN Failed to register uploaded object key=9yfya3if7aj5k6971nn1y7pnybz913xi.ls error="server returned 404: 404 page not found\n"12952026/10/04 20:03:34 INFO Signed narinfos id=2 count=112962026/10/04 20:03:34 INFO Uploading 1 narinfos12972026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12982026/10/04 20:03:34 INFO Signed narinfos id=1 count=212992026/10/04 20:03:34 INFO Uploading 2 narinfos1300--- PASS: TestService_healthCheckHandler (0.87s)1301=== CONT TestOrphanedObjectsGCStressTest13022026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/2/complete13032026/10/04 20:03:34 WARN Failed to register uploaded object key=v2gcdxgmsv7i353vhjj3haim07r5xf6v.narinfo error="server returned 404: 404 page not found\n"13042026/10/04 20:03:34 WARN Failed to register uploaded object key=a8r6kgrlnnha5hvpqcpy8krjzq8br9an.narinfo error="server returned 404: 404 page not found\n"13052026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete13062026/10/04 20:03:34 WARN Failed to register uploaded object key=9yfya3if7aj5k6971nn1y7pnybz913xi.narinfo error="server returned 404: 404 page not found\n"13072026/10/04 20:03:34 INFO Upload complete. (97ms)13082026/10/04 20:03:34 INFO Upload complete. (135ms)1309=== NAME TestClientSharedPathCommittedMidPush1310 client_integration_test.go:680: Retrieved narinfo from S3:1311 StorePath: /build/TestClientSharedPathCommittedMidPush683353041/001/store/a8r6kgrlnnha5hvpqcpy8krjzq8br9an-shared-dep1312 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1313 Compression: zstd1314 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821315 NarSize: 1361316 References: 1317 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1318 client_integration_test.go:680: Retrieved narinfo from S3:1319 StorePath: /build/TestClientSharedPathCommittedMidPush683353041/001/store/9yfya3if7aj5k6971nn1y7pnybz913xi-top1320 URL: nar/0zzwr5iqhklymfjw16bi4bsf5hscja2wgwgy5fmjyffnpm89xjs8.nar.zst1321 Compression: zstd1322 NarHash: sha256:0zzwr5iqhklymfjw16bi4bsf5hscja2wgwgy5fmjyffnpm89xjs81323 NarSize: 2241324 References: /build/TestClientSharedPathCommittedMidPush683353041/001/store/a8r6kgrlnnha5hvpqcpy8krjzq8br9an-shared-dep1325 CA: text:sha256:0k1g7as8pn4gp8fjn905i1ivsh4xk7z4ifabybrzzix53y8ar9nz1326--- PASS: TestClientSharedPathCommittedMidPush (1.01s)1327=== CONT TestIsValidCachePath1328=== RUN TestIsValidCachePath/narinfo1329=== PAUSE TestIsValidCachePath/narinfo1330=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1331=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1332=== RUN TestIsValidCachePath/nar_zst1333=== PAUSE TestIsValidCachePath/nar_zst1334=== RUN TestIsValidCachePath/nar_xz1335=== PAUSE TestIsValidCachePath/nar_xz1336=== RUN TestIsValidCachePath/nar_bz21337=== PAUSE TestIsValidCachePath/nar_bz21338=== RUN TestIsValidCachePath/nar_uncompressed1339=== PAUSE TestIsValidCachePath/nar_uncompressed1340=== RUN TestIsValidCachePath/ls1341=== PAUSE TestIsValidCachePath/ls1342=== RUN TestIsValidCachePath/log1343=== PAUSE TestIsValidCachePath/log1344=== RUN TestIsValidCachePath/realisation1345=== PAUSE TestIsValidCachePath/realisation1346=== RUN TestIsValidCachePath/nix-cache-info1347=== PAUSE TestIsValidCachePath/nix-cache-info1348=== RUN TestIsValidCachePath/index.html1349=== PAUSE TestIsValidCachePath/index.html1350=== RUN TestIsValidCachePath/traversal_parent1351=== PAUSE TestIsValidCachePath/traversal_parent1352=== RUN TestIsValidCachePath/traversal_in_middle1353=== PAUSE TestIsValidCachePath/traversal_in_middle1354=== RUN TestIsValidCachePath/invalid_char_e1355=== PAUSE TestIsValidCachePath/invalid_char_e1356=== RUN TestIsValidCachePath/invalid_char_u1357=== PAUSE TestIsValidCachePath/invalid_char_u1358=== RUN TestIsValidCachePath/random_path1359=== PAUSE TestIsValidCachePath/random_path1360=== RUN TestIsValidCachePath/empty1361=== PAUSE TestIsValidCachePath/empty1362=== RUN TestIsValidCachePath/leading_slash1363=== PAUSE TestIsValidCachePath/leading_slash1364=== RUN TestIsValidCachePath/wrong_extension1365=== PAUSE TestIsValidCachePath/wrong_extension1366=== RUN TestIsValidCachePath/short_hash1367=== PAUSE TestIsValidCachePath/short_hash1368=== CONT TestGCSweepDeliversEachKeyOnce13692026/10/04 20:03:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures13702026/10/04 20:03:34 INFO Garbage collection started13712026/10/04 20:03:34 INFO Aborted multipart uploads count=0 kept=013722026/10/04 20:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period13732026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes13742026/10/04 20:03:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13752026/10/04 20:03:34 INFO Uploading 68pmlbkd8713qkrsp7gy496ywnl38r2j-test-script (136B)1376=== NAME TestClientMultipleUploads1377 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2360004022/001/store/j3p5f70wm25qsyc1yy599sphcgagkhcs-test-file-0.txt1378--- PASS: TestReadProxy404 (0.83s)1379=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle13802026/10/04 20:03:34 WARN Failed to register uploaded object key=log/wzfrgf2hkxgpxsfiyfg4crxpq8s5b21f-test-script.drv error="server returned 404: 404 page not found\n"13812026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13822026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13832026/10/04 20:03:34 WARN Failed to register uploaded object key=68pmlbkd8713qkrsp7gy496ywnl38r2j.ls error="server returned 404: 404 page not found\n"13842026/10/04 20:03:34 INFO Signed narinfos id=1 count=113852026/10/04 20:03:34 INFO Uploading 1 narinfos13862026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete13872026/10/04 20:03:34 WARN Failed to register uploaded object key=68pmlbkd8713qkrsp7gy496ywnl38r2j.narinfo error="server returned 404: 404 page not found\n"13882026/10/04 20:03:34 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013892026/10/04 20:03:34 INFO Vacuumed table table=pending_closures13902026/10/04 20:03:34 INFO Upload complete. (61ms)13912026/10/04 20:03:34 INFO Vacuumed table table=pending_objects13922026/10/04 20:03:34 INFO Vacuumed table table=multipart_uploads1393=== NAME TestClientWithDependencies1394 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3144386950/001/store) requires matching store prefix13952026/10/04 20:03:34 INFO Vacuumed table table=closures13962026/10/04 20:03:34 INFO Vacuumed table table=objects1397--- PASS: TestClientWithDependencies (1.02s)1398=== CONT TestGCMetrics1399=== NAME TestClientMultipleUploads1400 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2360004022/001/store/2igdal3xg1yyhnj66migccxgcpra1xmd-test-file-1.txt1401=== NAME TestClientIntegration1402 client_integration_test.go:286: Created store path: /build/TestClientIntegration1091644840/002/store/na1hppfcv2wkzd6bj0fm90hvfyrhvs61-test-file.txt1403--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.30s)1404=== CONT TestGCSweepSkipsPendingObjects1405--- PASS: TestCacheStatsHandler (0.86s)1406=== CONT TestDeduplicatedObjectsRecordedAsPending1407=== NAME TestClientMultipleUploads1408 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2360004022/001/store/wly8bhwsl781a1y4vara5xvfq723pn63-test-file-2.txt14092026/10/04 20:03:34 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3203004381/001/proxy.sock14102026/10/04 20:03:34 INFO Starting HTTP server address=127.0.0.1:3673114112026/10/04 20:03:34 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14122026/10/04 20:03:34 INFO Shutdown signal received, draining in-flight requests timeout=10s1413--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.86s)1414=== CONT TestGCBugBareHashReferences1415=== NAME TestClientCADerivations1416 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations467282839/001/store/j7xjk0r0qvaw9f5c2msrj4h8maq5jq3k-ca-test14172026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes14182026/10/04 20:03:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14192026/10/04 20:03:34 INFO Uploading na1hppfcv2wkzd6bj0fm90hvfyrhvs61-test-file.txt (152B)14202026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14212026/10/04 20:03:34 WARN Failed to register uploaded object key=na1hppfcv2wkzd6bj0fm90hvfyrhvs61.ls error="server returned 404: 404 page not found\n"14222026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14232026/10/04 20:03:34 INFO Signed narinfos id=1 count=11424--- PASS: TestPresentReportsOnlyClosureRoots (0.74s)1425=== CONT TestPushDedupSurvivesConcurrentGC14262026/10/04 20:03:34 INFO Uploading 1 narinfos1427--- PASS: TestService_ReadAuthMiddleware (0.73s)1428=== CONT TestTombstonedObjectOfferedWithoutWaiting14292026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete14302026/10/04 20:03:34 WARN Failed to register uploaded object key=na1hppfcv2wkzd6bj0fm90hvfyrhvs61.narinfo error="server returned 404: 404 page not found\n"1431=== NAME TestClientCADerivations1432 client_ca_test.go:139: Found 1 dependencies (including self)14332026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes14342026/10/04 20:03:34 INFO Upload complete. (65ms)14352026/10/04 20:03:34 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14362026/10/04 20:03:34 INFO Uploading wly8bhwsl781a1y4vara5xvfq723pn63-test-file-2.txt (160B)14372026/10/04 20:03:34 INFO Uploading 2igdal3xg1yyhnj66migccxgcpra1xmd-test-file-1.txt (160B)14382026/10/04 20:03:34 INFO Uploading j3p5f70wm25qsyc1yy599sphcgagkhcs-test-file-0.txt (160B)14392026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14402026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14412026/10/04 20:03:34 WARN Failed to register uploaded object key=wly8bhwsl781a1y4vara5xvfq723pn63.ls error="server returned 404: 404 page not found\n"14422026/10/04 20:03:34 WARN Failed to register uploaded object key=j3p5f70wm25qsyc1yy599sphcgagkhcs.ls error="server returned 404: 404 page not found\n"14432026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14442026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14452026/10/04 20:03:34 WARN Failed to register uploaded object key=2igdal3xg1yyhnj66migccxgcpra1xmd.ls error="server returned 404: 404 page not found\n"14462026/10/04 20:03:34 INFO Signed narinfos id=1 count=314472026/10/04 20:03:34 INFO Uploading 3 narinfos14482026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete14492026/10/04 20:03:34 WARN Failed to register uploaded object key=wly8bhwsl781a1y4vara5xvfq723pn63.narinfo error="server returned 404: 404 page not found\n"14502026/10/04 20:03:34 WARN Failed to register uploaded object key=2igdal3xg1yyhnj66migccxgcpra1xmd.narinfo error="server returned 404: 404 page not found\n"14512026/10/04 20:03:34 WARN Failed to register uploaded object key=j3p5f70wm25qsyc1yy599sphcgagkhcs.narinfo error="server returned 404: 404 page not found\n"1452--- PASS: TestReadProxyNarStreaming (0.75s)1453=== CONT TestGCAdvisoryLockBlocksConcurrentRun14542026/10/04 20:03:34 INFO Upload complete. (61ms)1455=== NAME TestClientMultipleUploads1456 client_integration_test.go:369: Uploaded 3 paths in 97.521705ms1457--- PASS: TestClientMultipleUploads (1.07s)1458=== CONT TestService_AuthMiddleware_MTLSProxyHeader14592026/10/04 20:03:34 INFO All 1 paths already cached1460=== NAME TestClientIntegration1461 client_integration_test.go:312: Retrieved narinfo from S3:1462 StorePath: /build/TestClientIntegration1091644840/002/store/na1hppfcv2wkzd6bj0fm90hvfyrhvs61-test-file.txt1463 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1464 Compression: zstd1465 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11466 NarSize: 1521467 References: 1468 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11469 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1470 client_integration_test.go:313: Decompressed .ls content (64 bytes):1471 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1472 client_integration_test.go:316: Testing garbage collection...1473=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1474=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1475=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1476=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1477=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1478=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1479=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1480=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1481=== CONT TestGCTaskStore_ConflictDifferentParams1482--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1483=== CONT TestGCTaskStore_GetEmpty1484--- PASS: TestGCTaskStore_GetEmpty (0.00s)1485=== CONT TestConnectWaitsForAPeerMigration1486=== RUN TestService_RequireScope_OIDC/builder_may_write1487=== PAUSE TestService_RequireScope_OIDC/builder_may_write1488=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1489=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1490=== RUN TestService_RequireScope_OIDC/ops_may_admin1491=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1492=== RUN TestService_RequireScope_OIDC/ops_may_not_write1493=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1494=== RUN TestService_RequireScope_OIDC/reader_may_not_write1495=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1496=== RUN TestService_RequireScope_OIDC/static_token_may_admin1497=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1498=== RUN TestService_RequireScope_OIDC/static_token_may_write1499=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1500=== RUN TestService_RequireScope_OIDC/reader_may_read1501=== PAUSE TestService_RequireScope_OIDC/reader_may_read1502=== RUN TestService_RequireScope_OIDC/writer_implies_read1503=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1504=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1505=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1506=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1507=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1508=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1509=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1510=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1511=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1512=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1513=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1514=== CONT TestLeadElectsOneAndHandsOver15152026/10/04 20:03:34 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15162026/10/04 20:03:34 WARN mTLS auth: bound subjects configured but subject DN unavailable15172026/10/04 20:03:34 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1518--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.42s)1519=== CONT TestLeadEndsOnShutdown15202026/10/04 20:03:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures15212026/10/04 20:03:34 INFO Garbage collection started15222026/10/04 20:03:34 INFO Aborted multipart uploads count=0 kept=015232026/10/04 20:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period15242026/10/04 20:03:34 INFO Received uploads request method=POST path=/api/pending_closures15252026/10/04 20:03:34 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=015262026/10/04 20:03:34 INFO Vacuumed table table=pending_closures15272026/10/04 20:03:34 INFO Received push request method=POST path=/api/pushes15282026/10/04 20:03:34 INFO Vacuumed table table=pending_objects15292026/10/04 20:03:34 INFO Vacuumed table table=multipart_uploads15302026/10/04 20:03:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15312026/10/04 20:03:34 INFO Uploading j7xjk0r0qvaw9f5c2msrj4h8maq5jq3k-ca-test (144B)15322026/10/04 20:03:34 INFO Vacuumed table table=closures15332026/10/04 20:03:34 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15342026/10/04 20:03:34 WARN Failed to register uploaded object key=log/jqpigf9f27xxr0sm69ni0mfzf5yq6sc9-ca-test.drv error="server returned 404: 404 page not found\n"15352026/10/04 20:03:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15362026/10/04 20:03:34 WARN Failed to register uploaded object key=j7xjk0r0qvaw9f5c2msrj4h8maq5jq3k.ls error="server returned 404: 404 page not found\n"15372026/10/04 20:03:34 INFO Signed narinfos id=1 count=115382026/10/04 20:03:34 INFO Uploading 1 narinfos15392026/10/04 20:03:34 INFO Received complete push request method=POST path=/api/pushes/1/complete15402026/10/04 20:03:34 WARN Failed to register uploaded object key=j7xjk0r0qvaw9f5c2msrj4h8maq5jq3k.narinfo error="server returned 404: 404 page not found\n"1541--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1542=== CONT TestPendingClosureWriteTimeout/empty1543=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15442026/10/04 20:03:34 INFO Vacuumed table table=objects15452026/10/04 20:03:34 INFO Upload complete. (95ms)1546=== NAME TestClientCADerivations1547 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations467282839/001/store/j7xjk0r0qvaw9f5c2msrj4h8maq5jq3k-ca-test1548 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1549 Compression: zstd1550 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1551 NarSize: 1441552 References: 1553 Deriver: /build/TestClientCADerivations467282839/001/store/jqpigf9f27xxr0sm69ni0mfzf5yq6sc9-ca-test.drv1554 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1555 client_ca_test.go:185: Checking for realisation files in S3...1556 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1557 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15582026/10/04 20:03:34 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15592026/10/04 20:03:34 WARN Refused reserved pin name=worker-x86_64-linux15602026/10/04 20:03:34 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15612026/10/04 20:03:34 INFO Received create pin request method=POST path=/api/pins/my-app15622026/10/04 20:03:34 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1563--- PASS: TestCreatePin_ReservedPins (0.49s)1564=== CONT TestPendingClosureWriteTimeout/400_objects1565=== CONT TestPendingClosureWriteTimeout/670k_objects1566=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15672026/10/04 20:03:34 INFO Received uploads request method=POST path=/1568=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15692026/10/04 20:03:34 INFO Received complete multipart upload request method=POST path=/1570=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15712026/10/04 20:03:34 INFO Received request for more parts method=POST path=/1572=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15732026/10/04 20:03:34 INFO Received uploads request method=POST path=/1574--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1575 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1576 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1577 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1578 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1579=== CONT TestProxyWriteTimeout/narinfo1580=== CONT TestProxyWriteTimeout/unknown_size1581=== CONT TestProxyWriteTimeout/1_GiB_nar1582=== CONT TestProxyWriteTimeout/10_GiB_nar1583--- PASS: TestProxyWriteTimeout (0.00s)1584 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1585 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1586 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1587 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1588=== CONT TestIsValidUploadKey/narinfo1589=== CONT TestIsValidUploadKey/unknown_type1590=== CONT TestIsValidUploadKey/empty_key1591=== CONT TestIsValidUploadKey/absolute1592=== CONT TestIsValidUploadKey/traversal_nar1593=== CONT TestIsValidUploadKey/traversal1594=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1595=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1596=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1597=== CONT TestIsValidUploadKey/index.html1598=== CONT TestIsValidUploadKey/nix-cache-info1599=== CONT TestIsValidUploadKey/realisation_plus_in_output1600=== CONT TestIsValidUploadKey/realisation1601=== CONT TestIsValidUploadKey/build_log_equals1602=== CONT TestIsValidUploadKey/build_log_question_mark1603=== CONT TestIsValidUploadKey/build_log_plus_in_name1604=== CONT TestIsValidUploadKey/build_log_home-manager_file1605=== CONT TestIsValidUploadKey/build_log1606=== CONT TestIsValidUploadKey/listing1607=== CONT TestIsValidUploadKey/nar_zst1608=== CONT TestIsValidUploadKey/nar_plain1609=== CONT TestIsValidUploadKey/nar_xz1610--- PASS: TestIsValidUploadKey (0.08s)1611 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1612 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1613 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1614 --- PASS: TestIsValidUploadKey/absolute (0.00s)1615 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1616 --- PASS: TestIsValidUploadKey/traversal (0.00s)1617 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1618 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1619 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1620 --- PASS: TestIsValidUploadKey/index.html (0.00s)1621 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1622 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1623 --- PASS: TestIsValidUploadKey/realisation (0.00s)1624 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1625 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1626 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1627 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1628 --- PASS: TestIsValidUploadKey/build_log (0.00s)1629 --- PASS: TestIsValidUploadKey/listing (0.00s)1630 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1631 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1632 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1633=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16342026/10/04 20:03:34 INFO Received uploads request method=POST path=/16352026/10/04 20:03:34 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"16362026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures16372026/10/04 20:03:35 INFO Aborted multipart uploads count=0 kept=01638=== NAME TestClientCADerivations1639 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1640 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1641 error: binary cache 's3://bucket56?endpoint=http://localhost:43283®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations467282839/001/store'1642 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116432026/10/04 20:03:35 WARN Force mode enabled - objects will be deleted immediately without grace period1644--- PASS: TestClientCADerivations (1.18s)1645=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16462026/10/04 20:03:35 INFO Received request for more parts method=POST path=/16472026/10/04 20:03:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=016482026/10/04 20:03:35 INFO Vacuumed table table=pending_closures16492026/10/04 20:03:35 INFO Vacuumed table table=pending_objects16502026/10/04 20:03:35 INFO Vacuumed table table=multipart_uploads16512026/10/04 20:03:35 INFO Vacuumed table table=closures16522026/10/04 20:03:35 INFO Vacuumed table table=objects1653--- PASS: TestGCSweepDeliversEachKeyOnce (0.43s)1654=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16552026/10/04 20:03:35 INFO Received complete multipart upload request method=POST path=/16562026/10/04 20:03:35 INFO Aborted multipart uploads count=0 kept=016572026/10/04 20:03:35 WARN Force mode enabled - objects will be deleted immediately without grace period16582026/10/04 20:03:35 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=016592026/10/04 20:03:35 INFO Vacuumed table table=pending_closures16602026/10/04 20:03:35 INFO Vacuumed table table=pending_objects16612026/10/04 20:03:35 INFO Vacuumed table table=multipart_uploads16622026/10/04 20:03:35 INFO Vacuumed table table=closures16632026/10/04 20:03:35 INFO Vacuumed table table=objects16642026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures1665--- PASS: TestGCMetrics (0.38s)1666=== CONT TestPush_RejectsBadRequests/bad_root16672026/10/04 20:03:35 INFO Received push request method=POST path=/api/pushes1668=== CONT TestPush_RejectsBadRequests/no_roots16692026/10/04 20:03:35 INFO Received push request method=POST path=/api/pushes1670=== CONT TestPush_RejectsBadRequests/root_not_in_objects16712026/10/04 20:03:35 INFO Received push request method=POST path=/api/pushes1672=== CONT TestPush_RejectsBadRequests/no_objects16732026/10/04 20:03:35 INFO Received push request method=POST path=/api/pushes1674=== CONT TestServerTLSConfig/no_client_CA1675=== CONT TestServerTLSConfig/not_a_PEM_file1676--- PASS: TestPush_RejectsBadRequests (0.33s)1677 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1678 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1679 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1680 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1681=== CONT TestServerTLSConfig/missing_CA_file1682--- PASS: TestServerTLSConfig (0.00s)1683 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1684 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1685 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1686=== CONT TestResolveDBConnectionString/flag_wins1687=== CONT TestResolveDBConnectionString/nothing_configured1688=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1689=== CONT TestResolveDBConnectionString/missing_file_is_an_error1690=== CONT TestResolveDBConnectionString/file_when_flag_empty1691=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1692--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.34s)1693=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1694--- PASS: TestResolveDBConnectionString (0.00s)1695 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1696 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1697 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1698 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1699 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17002026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures17012026/10/04 20:03:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1702=== CONT TestClientErrorHandling/InvalidStorePath17032026/10/04 20:03:35 INFO Aborted multipart uploads count=0 kept=017042026/10/04 20:03:35 WARN Force mode enabled - objects will be deleted immediately without grace period17052026/10/04 20:03:35 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=01706=== CONT TestClientErrorHandling/InvalidAuthToken17072026/10/04 20:03:35 INFO Vacuumed table table=pending_closures17082026/10/04 20:03:35 INFO Vacuumed table table=pending_objects17092026/10/04 20:03:35 INFO Vacuumed table table=multipart_uploads1710--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.63s)17112026/10/04 20:03:35 INFO Vacuumed table table=closures1712=== CONT TestClientErrorHandling/ServerNotAvailable17132026/10/04 20:03:35 INFO Vacuumed table table=objects17142026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures1715--- PASS: TestGCSweepSkipsPendingObjects (0.41s)1716=== CONT TestParseSingleRange/none1717=== CONT TestParseSingleRange/start_far_past_EOF1718=== CONT TestParseSingleRange/start_past_EOF1719=== CONT TestParseSingleRange/single_byte1720=== CONT TestParseSingleRange/suffix_exceeds_size1721=== CONT TestParseSingleRange/suffix1722=== CONT TestParseSingleRange/end_clamped_to_size1723=== CONT TestParseSingleRange/open-ended1724=== CONT TestParseSingleRange/closed1725=== CONT TestParseSingleRange/malformed_end_before_start1726=== CONT TestParseSingleRange/malformed_both_empty1727=== CONT TestParseSingleRange/malformed_no_dash1728=== CONT TestParseSingleRange/multi-range_ignored1729=== CONT TestParseSingleRange/unknown_unit1730--- PASS: TestParseSingleRange (0.00s)1731 --- PASS: TestParseSingleRange/none (0.00s)1732 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1733 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1734 --- PASS: TestParseSingleRange/single_byte (0.00s)1735 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1736 --- PASS: TestParseSingleRange/suffix (0.00s)1737 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1738 --- PASS: TestParseSingleRange/open-ended (0.00s)1739 --- PASS: TestParseSingleRange/closed (0.00s)1740 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1741 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1742 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1743 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1744 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1745=== CONT TestCacheConfigHandler/full_config,_no_issuer1746=== CONT TestCacheConfigHandler/no_signing_keys1747=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1748=== CONT TestCacheConfigHandler/no_cache_url_configured1749--- PASS: TestCacheConfigHandler (0.00s)1750 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1751 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1752 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1753 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1754=== CONT TestIsValidCachePath/narinfo1755=== CONT TestIsValidCachePath/short_hash1756=== CONT TestIsValidCachePath/wrong_extension1757=== CONT TestIsValidCachePath/leading_slash1758=== CONT TestIsValidCachePath/empty1759=== CONT TestIsValidCachePath/random_path1760=== CONT TestIsValidCachePath/invalid_char_e1761=== CONT TestIsValidCachePath/traversal_in_middle1762=== CONT TestIsValidCachePath/traversal_parent1763=== CONT TestIsValidCachePath/index.html1764=== CONT TestIsValidCachePath/invalid_char_u1765=== CONT TestIsValidCachePath/realisation1766=== CONT TestIsValidCachePath/log1767=== CONT TestIsValidCachePath/ls1768=== CONT TestIsValidCachePath/nar_uncompressed1769=== CONT TestIsValidCachePath/nar_bz21770=== CONT TestIsValidCachePath/nar_xz1771=== CONT TestIsValidCachePath/nar_zst1772=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1773=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1774--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.34s)1775=== CONT TestIsValidCachePath/nix-cache-info1776--- PASS: TestIsValidCachePath (0.00s)1777 --- PASS: TestIsValidCachePath/narinfo (0.00s)1778 --- PASS: TestIsValidCachePath/short_hash (0.00s)1779 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1780 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1781 --- PASS: TestIsValidCachePath/empty (0.00s)1782 --- PASS: TestIsValidCachePath/random_path (0.00s)1783 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1784 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1785 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1786 --- PASS: TestIsValidCachePath/index.html (0.00s)1787 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1788 --- PASS: TestIsValidCachePath/realisation (0.00s)1789 --- PASS: TestIsValidCachePath/log (0.00s)1790 --- PASS: TestIsValidCachePath/ls (0.00s)1791 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1792 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1793 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1794 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1795 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1796 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1797=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1798=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17992026/10/04 20:03:35 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]1800=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1801=== CONT TestService_RequireScope_OIDC/builder_may_write18022026/10/04 20:03:35 WARN Authentication failed token_preview=eyJhbGciOi...7pNRDb7bRw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1803=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1804=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1805=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc18062026/10/04 20:03:35 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1807=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1808--- PASS: TestService_AuthMiddleware_OIDC (0.80s)1809 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1810 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1811 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1812 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1813=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1814=== CONT TestService_RequireScope_OIDC/writer_implies_read1815=== CONT TestService_RequireScope_OIDC/reader_may_read1816=== CONT TestService_RequireScope_OIDC/static_token_may_write1817=== CONT TestService_RequireScope_OIDC/static_token_may_admin1818=== CONT TestService_RequireScope_OIDC/reader_may_not_write1819=== CONT TestService_RequireScope_OIDC/ops_may_not_write1820=== CONT TestService_RequireScope_OIDC/ops_may_admin1821=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1822--- PASS: TestService_RequireScope_OIDC (0.89s)1823 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1825 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1826 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1827 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1828 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1829 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1830 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1831 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18372026/10/04 20:03:35 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161838--- PASS: TestReadProxyNarinfo (0.64s)18392026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures18402026/10/04 20:03:35 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1841--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.35s)1842--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.35s)18432026/10/04 20:03:35 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18442026/10/04 20:03:35 INFO lead: acquired remote=192.0.2.1:123418452026/10/04 20:03:35 INFO lead: acquired remote=192.0.2.1:123418462026/10/04 20:03:35 INFO Aborted multipart uploads count=0 kept=018472026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures18482026/10/04 20:03:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018492026/10/04 20:03:35 INFO Vacuumed table table=pending_closures18502026/10/04 20:03:35 INFO Vacuumed table table=pending_objects18512026/10/04 20:03:35 INFO Vacuumed table table=multipart_uploads18522026/10/04 20:03:35 INFO Vacuumed table table=closures18532026/10/04 20:03:35 INFO Vacuumed table table=objects1854--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.36s)18552026/10/04 20:03:35 INFO Aborted multipart uploads count=0 kept=018562026/10/04 20:03:35 WARN Force mode enabled - objects will be deleted immediately without grace period18572026/10/04 20:03:35 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=018582026/10/04 20:03:35 INFO Vacuumed table table=pending_closures18592026/10/04 20:03:35 INFO Vacuumed table table=pending_objects18602026/10/04 20:03:35 INFO Vacuumed table table=multipart_uploads18612026/10/04 20:03:35 INFO Vacuumed table table=closures18622026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures18632026/10/04 20:03:35 INFO Vacuumed table table=objects1864--- PASS: TestPushDedupSurvivesConcurrentGC (0.46s)18652026/10/04 20:03:35 INFO Aborted multipart uploads count=0 kept=018662026/10/04 20:03:35 WARN Force mode enabled - objects will be deleted immediately without grace period18672026/10/04 20:03:35 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=018682026/10/04 20:03:35 INFO Received uploads request method=POST path=/api/pending_closures18692026/10/04 20:03:35 INFO Vacuumed table table=pending_closures18702026/10/04 20:03:35 INFO Vacuumed table table=pending_objects18712026/10/04 20:03:35 INFO Vacuumed table table=multipart_uploads18722026/10/04 20:03:35 INFO Vacuumed table table=closures18732026/10/04 20:03:35 INFO Vacuumed table table=objects18742026/10/04 20:03:35 INFO Aborted multipart uploads count=0 kept=018752026/10/04 20:03:35 WARN Force mode enabled - objects will be deleted immediately without grace period18762026/10/04 20:03:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=018772026/10/04 20:03:35 INFO Vacuumed table table=pending_closures18782026/10/04 20:03:35 INFO Vacuumed table table=pending_objects18792026/10/04 20:03:35 INFO Vacuumed table table=multipart_uploads18802026/10/04 20:03:35 INFO Vacuumed table table=closures18812026/10/04 20:03:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.809809ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18822026/10/04 20:03:35 INFO Vacuumed table table=objects1883--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1884 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.21s)1885 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.24s)1886--- PASS: TestGCBugBareHashReferences (0.56s)18872026/10/04 20:03:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18882026/10/04 20:03:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18892026/10/04 20:03:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.416812ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18902026/10/04 20:03:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=860.151974ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1891=== NAME TestOrphanedObjectsGCStressTest1892 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1893--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1894 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1895 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1896 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.06s)1897=== NAME TestOrphanedObjectsGCStressTest1898 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1899--- PASS: TestPendingClosureWriteTimeout (0.08s)1900 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1901 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1902 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1903 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.11s)1904=== NAME TestOrphanedObjectsGCStressTest1905 orphaned_objects_gc_test.go:509: Stress test completed successfully:1906 orphaned_objects_gc_test.go:510: - Active objects preserved: 201907 orphaned_objects_gc_test.go:511: - Objects deleted: 2101908 orphaned_objects_gc_test.go:512: - Total GC'd: 2101909--- PASS: TestOrphanedObjectsGCStressTest (1.66s)19102026/10/04 20:03:36 INFO lead: released remote=192.0.2.1:12341911--- PASS: TestLeadEndsOnShutdown (1.39s)19122026/10/04 20:03:36 INFO lead: released remote=192.0.2.1:123419132026/10/04 20:03:36 INFO lead: acquired remote=192.0.2.1:123419142026/10/04 20:03:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019152026/10/04 20:03:36 INFO Received create pin request method=POST path=/api/pins/myapp19162026/10/04 20:03:36 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC25062778/001/store/jd32m1hvcfawf42d1s57s0mm75sn7v6m-pinned-file.txt narinfo_key=jd32m1hvcfawf42d1s57s0mm75sn7v6m.narinfo19172026/10/04 20:03:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures19182026/10/04 20:03:36 INFO Garbage collection started19192026/10/04 20:03:36 INFO Aborted multipart uploads count=0 kept=019202026/10/04 20:03:36 WARN Force mode enabled - objects will be deleted immediately without grace period19212026/10/04 20:03:36 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=019222026/10/04 20:03:36 INFO Vacuumed table table=pending_closures19232026/10/04 20:03:36 INFO Vacuumed table table=pending_objects19242026/10/04 20:03:36 INFO Vacuumed table table=multipart_uploads19252026/10/04 20:03:36 INFO Vacuumed table table=closures19262026/10/04 20:03:36 INFO Vacuumed table table=objects19272026/10/04 20:03:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.644369764s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19282026/10/04 20:03:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01929=== NAME TestClientIntegration1930 client_integration_test.go:323: Objects in database after GC:1931 client_integration_test.go:323: Successfully deleted all objects with GC --force1932--- PASS: TestClientIntegration (3.05s)19332026/10/04 20:03:37 INFO lead: released remote=192.0.2.1:12341934--- PASS: TestLeadElectsOneAndHandsOver (2.75s)1935--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.64s)19362026/10/04 20:03:38 WARN Rate limiter enabled after throttle name=s3-test rate=519372026/10/04 20:03:38 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1938=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1939 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101940 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001941--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.74s)19422026/10/04 20:03:38 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19432026/10/04 20:03:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.888827ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1944=== NAME TestPinProtectsFromGC1945 client_integration_test.go:840: Pin successfully protected closure from garbage collection1946--- PASS: TestPinProtectsFromGC (5.11s)19472026/10/04 20:03:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.040753ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19482026/10/04 20:03:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=786.617698ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19492026/10/04 20:03:39 INFO Aborted multipart uploads count=1 kept=019502026/10/04 20:03:39 INFO Received cleanup request method=DELETE path=/api/pending_closures19512026/10/04 20:03:39 INFO Aborted multipart uploads count=1 kept=01952--- PASS: TestPendingCleanupUsesOneCutoff (6.54s)19532026/10/04 20:03:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.740869603s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1954--- PASS: TestConnectWaitsForAPeerMigration (5.13s)19552026/10/04 20:03:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"19562026/10/04 20:03:41 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19572026/10/04 20:03:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.048654ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19582026/10/04 20:03:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.258393ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19592026/10/04 20:03:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=780.801057ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19602026/10/04 20:03:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.583155115s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19612026/10/04 20:03:44 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19622026/10/04 20:03:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.608832ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19632026/10/04 20:03:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=415.906722ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19642026/10/04 20:03:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=777.621228ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19652026/10/04 20:03:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.476794864s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1966--- PASS: TestClientErrorHandling (0.00s)1967 --- PASS: TestClientErrorHandling/InvalidStorePath (0.22s)1968 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)1969 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.69s)1970PASS19712026-10-04 20:03:48.031 UTC [127] LOG: received smart shutdown request19722026-10-04 20:03:48.036 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 119732026-10-04 20:03:48.050 UTC [132] LOG: shutting down19742026-10-04 20:03:48.050 UTC [132] LOG: checkpoint starting: shutdown immediate19752026-10-04 20:03:48.951 UTC [132] LOG: checkpoint complete: wrote 10840 buffers (66.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.193 s, sync=0.678 s, total=0.901 s; sync files=29992, longest=0.012 s, average=0.001 s; distance=414789 kB, estimate=414789 kB; lsn=0/1AC771F8, redo lsn=0/1AC771F819762026-10-04 20:03:49.031 UTC [127] LOG: database system is shut down1977Running OIDC tests...1978=== RUN TestAudienceForIssuer1979=== PAUSE TestAudienceForIssuer1980=== RUN TestGlobMatch1981=== PAUSE TestGlobMatch1982=== RUN TestValidateToken_ValidToken1983=== PAUSE TestValidateToken_ValidToken1984=== RUN TestValidateToken_WrongAudience1985=== PAUSE TestValidateToken_WrongAudience1986=== RUN TestValidateToken_Expired1987=== PAUSE TestValidateToken_Expired1988=== RUN TestValidateToken_BoundClaimsMismatch1989=== PAUSE TestValidateToken_BoundClaimsMismatch1990=== RUN TestValidateToken_BoundSubjectMismatch1991=== PAUSE TestValidateToken_BoundSubjectMismatch1992=== RUN TestValidateToken_MultipleProviders1993=== PAUSE TestValidateToken_MultipleProviders1994=== RUN TestValidateToken_NoMatchingProvider1995=== PAUSE TestValidateToken_NoMatchingProvider1996=== RUN TestValidateToken_KubernetesServiceAccount1997=== PAUSE TestValidateToken_KubernetesServiceAccount1998=== RUN TestNewValidator_KubernetesRequiresCA1999=== PAUSE TestNewValidator_KubernetesRequiresCA2000=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2001=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2002=== RUN TestPins_ReservedForMatchingRule2003=== PAUSE TestPins_ReservedForMatchingRule2004=== RUN TestPins_TopLevelShorthand2005=== PAUSE TestPins_TopLevelShorthand2006=== RUN TestPins_ConfigValidation2007=== PAUSE TestPins_ConfigValidation2008=== RUN TestScopes_LegacyProviderDefaultsToWrite2009=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2010=== RUN TestScopes_Rules2011=== PAUSE TestScopes_Rules2012=== RUN TestScopes_ConfigValidation2013=== PAUSE TestScopes_ConfigValidation2014=== CONT TestAudienceForIssuer2015=== CONT TestPins_ConfigValidation2016--- PASS: TestAudienceForIssuer (0.00s)2017=== CONT TestValidateToken_NoMatchingProvider2018=== CONT TestValidateToken_KubernetesServiceAccount2019=== CONT TestPins_ReservedForMatchingRule2020=== CONT TestScopes_Rules2021=== CONT TestScopes_ConfigValidation2022=== CONT TestScopes_LegacyProviderDefaultsToWrite2023=== CONT TestPins_TopLevelShorthand2024=== CONT TestValidateToken_Expired2025=== CONT TestValidateToken_MultipleProviders2026=== CONT TestValidateToken_ValidToken2027=== CONT TestValidateToken_WrongAudience2028=== CONT TestValidateToken_BoundSubjectMismatch2029=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2030=== CONT TestNewValidator_KubernetesRequiresCA2031--- PASS: TestPins_ConfigValidation (0.00s)2032=== CONT TestGlobMatch2033=== RUN TestGlobMatch/foo_foo2034=== PAUSE TestGlobMatch/foo_foo2035=== CONT TestValidateToken_BoundClaimsMismatch2036=== RUN TestGlobMatch/foo_bar2037=== PAUSE TestGlobMatch/foo_bar2038=== RUN TestGlobMatch/*_2039=== PAUSE TestGlobMatch/*_2040=== RUN TestGlobMatch/*_anything2041=== PAUSE TestGlobMatch/*_anything2042--- PASS: TestScopes_ConfigValidation (0.00s)2043=== RUN TestGlobMatch/foo*_foo2044=== PAUSE TestGlobMatch/foo*_foo2045=== RUN TestGlobMatch/foo*_foobar2046=== PAUSE TestGlobMatch/foo*_foobar2047=== RUN TestGlobMatch/foo*_bar2048=== PAUSE TestGlobMatch/foo*_bar2049=== RUN TestGlobMatch/*bar_bar2050=== PAUSE TestGlobMatch/*bar_bar2051=== RUN TestGlobMatch/*bar_foobar2052=== PAUSE TestGlobMatch/*bar_foobar2053=== RUN TestGlobMatch/*bar_foo2054=== PAUSE TestGlobMatch/*bar_foo2055=== RUN TestGlobMatch/foo*bar_foobar2056=== PAUSE TestGlobMatch/foo*bar_foobar2057=== RUN TestGlobMatch/foo*bar_foo123bar2058=== PAUSE TestGlobMatch/foo*bar_foo123bar2059=== RUN TestGlobMatch/foo*bar_foobarbaz2060=== PAUSE TestGlobMatch/foo*bar_foobarbaz2061=== RUN TestGlobMatch/*/*_foo/bar2062=== PAUSE TestGlobMatch/*/*_foo/bar2063=== RUN TestGlobMatch/*/*_foo2064=== PAUSE TestGlobMatch/*/*_foo2065=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2066=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2067=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02068=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02069=== RUN TestGlobMatch/refs/*/main_refs/heads/main2070=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2071=== RUN TestGlobMatch/fo?_foo2072=== PAUSE TestGlobMatch/fo?_foo2073=== RUN TestGlobMatch/fo?_fo2074=== PAUSE TestGlobMatch/fo?_fo2075=== RUN TestGlobMatch/fo?_fooo2076=== PAUSE TestGlobMatch/fo?_fooo2077=== RUN TestGlobMatch/?oo_foo2078=== PAUSE TestGlobMatch/?oo_foo2079=== RUN TestGlobMatch/?oo_boo2080=== PAUSE TestGlobMatch/?oo_boo2081=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2082=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2083=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2084=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2085=== CONT TestGlobMatch/foo_foo2086=== CONT TestGlobMatch/?oo_foo2087=== CONT TestGlobMatch/foo*_foobar2088=== CONT TestGlobMatch/foo*bar_foobarbaz2089=== CONT TestGlobMatch/fo?_fo2090=== CONT TestGlobMatch/fo?_foo2091=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2092=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02093=== CONT TestGlobMatch/*/*_foo2094=== CONT TestGlobMatch/*/*_foo/bar2095=== CONT TestGlobMatch/*bar_foo2096=== CONT TestGlobMatch/foo*bar_foo123bar2097=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2098=== CONT TestGlobMatch/?oo_boo2099=== CONT TestGlobMatch/*bar_bar2100=== CONT TestGlobMatch/foo*_bar2101=== CONT TestGlobMatch/foo*_foo2102=== CONT TestGlobMatch/*_anything2103=== CONT TestGlobMatch/*_2104=== CONT TestGlobMatch/foo_bar2105=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2106=== CONT TestGlobMatch/refs/*/main_refs/heads/main2107=== CONT TestGlobMatch/fo?_fooo2108=== CONT TestGlobMatch/foo*bar_foobar2109=== CONT TestGlobMatch/*bar_foobar2110--- PASS: TestGlobMatch (0.00s)2111 --- PASS: TestGlobMatch/foo_foo (0.00s)2112 --- PASS: TestGlobMatch/?oo_foo (0.00s)2113 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2114 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2115 --- PASS: TestGlobMatch/fo?_fo (0.00s)2116 --- PASS: TestGlobMatch/fo?_foo (0.00s)2117 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2118 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2119 --- PASS: TestGlobMatch/*/*_foo (0.00s)2120 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2121 --- PASS: TestGlobMatch/*bar_foo (0.00s)2122 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2123 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2124 --- PASS: TestGlobMatch/?oo_boo (0.00s)2125 --- PASS: TestGlobMatch/*bar_bar (0.00s)2126 --- PASS: TestGlobMatch/foo*_bar (0.00s)2127 --- PASS: TestGlobMatch/foo*_foo (0.00s)2128 --- PASS: TestGlobMatch/*_anything (0.00s)2129 --- PASS: TestGlobMatch/*_ (0.00s)2130 --- PASS: TestGlobMatch/foo_bar (0.00s)2131 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2132 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2133 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2134 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2135 --- PASS: TestGlobMatch/*bar_foobar (0.00s)21362026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33047/oidc2137--- PASS: TestPins_ReservedForMatchingRule (0.04s)21382026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45785/oidc21392026/10/04 20:03:50 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232140--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2141--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)21422026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39229/oidc2143--- PASS: TestValidateToken_Expired (0.08s)21442026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33623/oidc21452026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46725/oidc2146--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)2147--- PASS: TestValidateToken_ValidToken (0.12s)21482026/10/04 20:03:50 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:421072149--- PASS: TestValidateToken_KubernetesServiceAccount (0.16s)21502026/10/04 20:03:50 http: TLS handshake error from 127.0.0.1:57402: remote error: tls: bad certificate2151--- PASS: TestNewValidator_KubernetesRequiresCA (0.21s)21522026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32783/oidc2153--- PASS: TestValidateToken_WrongAudience (0.27s)21542026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40109/oidc2155--- PASS: TestScopes_Rules (0.31s)21562026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35801/oidc2157--- PASS: TestValidateToken_BoundSubjectMismatch (0.31s)21582026/10/04 20:03:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34367/oidc2159--- PASS: TestPins_TopLevelShorthand (0.35s)21602026/10/04 20:03:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35265/oidc2161--- PASS: TestValidateToken_NoMatchingProvider (0.37s)21622026/10/04 20:03:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42105/oidc21632026/10/04 20:03:50 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34055/oidc2164--- PASS: TestValidateToken_MultipleProviders (0.42s)2165PASS2166Running hook tests...2167=== RUN TestSendPathsEmpty2168=== PAUSE TestSendPathsEmpty2169=== RUN TestQueueEnqueueAndFetch2170=== PAUSE TestQueueEnqueueAndFetch2171=== RUN TestQueueDeduplication2172=== PAUSE TestQueueDeduplication2173=== RUN TestQueueRemove2174=== PAUSE TestQueueRemove2175=== RUN TestQueueFetchBatchLimit2176=== PAUSE TestQueueFetchBatchLimit2177=== RUN TestQueueRetryMovesToBack2178=== PAUSE TestQueueRetryMovesToBack2179=== RUN TestQueueFetchRemoveLifecycle2180=== PAUSE TestQueueFetchRemoveLifecycle2181=== RUN TestQueueConcurrentWriters2182=== PAUSE TestQueueConcurrentWriters2183=== RUN TestQueueRemoveLargeClosure2184=== PAUSE TestQueueRemoveLargeClosure2185=== RUN TestServerClientIntegration2186=== PAUSE TestServerClientIntegration2187=== RUN TestServerQueueError2188=== PAUSE TestServerQueueError2189=== RUN TestGetListenerSocketActivation2190 server_test.go:210: === RUN TestGetListenerSocketActivation2191 --- PASS: TestGetListenerSocketActivation (0.00s)2192 PASS2193 2194--- PASS: TestGetListenerSocketActivation (0.01s)2195=== RUN TestDrainIsolatesPoisonPath2196=== PAUSE TestDrainIsolatesPoisonPath2197=== RUN TestRunNotBlockedByPoisonHead2198=== PAUSE TestRunNotBlockedByPoisonHead2199=== RUN TestDrainGivesUpWhenServerDown2200=== PAUSE TestDrainGivesUpWhenServerDown2201=== RUN TestFailedPathPrunedByLaterClosure2202=== PAUSE TestFailedPathPrunedByLaterClosure2203=== RUN TestWorkerUploadsAndRemoves2204=== PAUSE TestWorkerUploadsAndRemoves2205=== RUN TestWorkerSkipsGCdPaths2206=== PAUSE TestWorkerSkipsGCdPaths2207=== RUN TestWorkerPrunesClosureDeps2208=== PAUSE TestWorkerPrunesClosureDeps2209=== RUN TestDrainTimeout2210=== PAUSE TestDrainTimeout2211=== CONT TestSendPathsEmpty2212=== CONT TestRunNotBlockedByPoisonHead2213=== CONT TestWorkerSkipsGCdPaths2214--- PASS: TestSendPathsEmpty (0.00s)2215=== CONT TestQueueFetchRemoveLifecycle2216=== CONT TestQueueRetryMovesToBack2217=== CONT TestQueueFetchBatchLimit2218=== CONT TestDrainIsolatesPoisonPath2219=== CONT TestQueueRemove2220=== CONT TestQueueDeduplication2221=== CONT TestServerQueueError2222=== CONT TestQueueEnqueueAndFetch2223=== CONT TestServerClientIntegration2224=== CONT TestQueueRemoveLargeClosure2225=== CONT TestFailedPathPrunedByLaterClosure2226=== CONT TestWorkerUploadsAndRemoves22272026/10/04 20:03:50 ERROR Failed to queue paths error="permission denied" count=12228=== CONT TestQueueConcurrentWriters2229=== CONT TestDrainTimeout2230=== CONT TestDrainGivesUpWhenServerDown2231=== CONT TestWorkerPrunesClosureDeps2232--- PASS: TestServerQueueError (0.00s)2233--- PASS: TestServerClientIntegration (0.00s)22342026/10/04 20:03:50 INFO Uploading batch count=222352026/10/04 20:03:50 INFO Uploading batch count=122362026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=122372026/10/04 20:03:50 INFO Upload queue status pending=22238--- PASS: TestQueueRetryMovesToBack (0.02s)2239--- PASS: TestQueueDeduplication (0.02s)22402026/10/04 20:03:50 INFO Uploading batch count=22241--- PASS: TestQueueFetchBatchLimit (0.01s)22422026/10/04 20:03:50 INFO Upload queue status pending=222432026/10/04 20:03:50 INFO Uploading batch count=122442026/10/04 20:03:50 INFO Uploading batch count=422452026/10/04 20:03:50 INFO Uploading batch count=122462026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=422472026/10/04 20:03:50 INFO Upload queue status pending=322482026/10/04 20:03:50 INFO Uploading batch count=222492026/10/04 20:03:50 INFO Uploading batch count=122502026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=122512026/10/04 20:03:50 INFO Upload queue status pending=222522026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=222532026/10/04 20:03:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1539669491/002/a2254--- PASS: TestQueueEnqueueAndFetch (0.02s)22552026/10/04 20:03:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1708109381/002/nonexistent22562026/10/04 20:03:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3208458967/002/bbb2257--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22582026/10/04 20:03:50 INFO Uploading batch count=122592026/10/04 20:03:50 INFO Uploading batch count=122602026/10/04 20:03:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1539669491/002/b2261--- PASS: TestQueueRemove (0.02s)22622026/10/04 20:03:50 INFO Uploading batch count=122632026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=122642026/10/04 20:03:50 INFO Uploading batch count=222652026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=222662026/10/04 20:03:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1539669491/002/c22672026/10/04 20:03:50 INFO Uploading batch count=122682026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=122692026/10/04 20:03:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1539669491/002/d22702026/10/04 20:03:50 INFO Uploading batch count=22271--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22722026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=222732026/10/04 20:03:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1539669491/002/e22742026/10/04 20:03:50 INFO Uploading batch count=122752026/10/04 20:03:50 ERROR Upload failed error="upload failed" count=122762026/10/04 20:03:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1539669491/002/f22772026/10/04 20:03:50 ERROR Drain finished with paths left in queue remaining=122782026/10/04 20:03:50 ERROR Drain finished with paths left in queue remaining=102279--- PASS: TestDrainIsolatesPoisonPath (0.02s)2280--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2281--- PASS: TestWorkerUploadsAndRemoves (0.03s)2282--- PASS: TestWorkerSkipsGCdPaths (0.04s)2283--- PASS: TestWorkerPrunesClosureDeps (0.03s)2284--- PASS: TestQueueRemoveLargeClosure (0.14s)2285--- PASS: TestQueueConcurrentWriters (0.16s)22862026/10/04 20:03:51 ERROR Upload failed error="context deadline exceeded" count=222872026/10/04 20:03:51 ERROR Drain finished with paths left in queue remaining=42288--- PASS: TestDrainTimeout (0.21s)22892026/10/04 20:03:51 INFO Uploading batch count=122902026/10/04 20:03:51 INFO Uploading batch count=122912026/10/04 20:03:51 INFO Uploading batch count=122922026/10/04 20:03:51 ERROR Upload failed error="upload failed" count=122932026/10/04 20:03:51 INFO Uploading batch count=122942026/10/04 20:03:51 ERROR Upload failed error="upload failed" count=122952026/10/04 20:03:51 INFO Uploading batch count=122962026/10/04 20:03:51 ERROR Upload failed error="upload failed" count=122972026/10/04 20:03:51 INFO Uploading batch count=122982026/10/04 20:03:51 ERROR Upload failed error="upload failed" count=122992026/10/04 20:03:51 ERROR Drain finished with paths left in queue remaining=12300--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2301PASS