niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #358
· 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 TestResolveStorePath101=== CONT TestScriptTokenScriptFails102=== CONT TestDumpPathWriterError103=== CONT TestScriptTokenEmptyCommand104--- PASS: TestScriptTokenEmptyCommand (0.00s)105=== CONT TestStreamPushIsolatesFailures106=== CONT TestPathInfoHashCompatibility107=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)108=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)109=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon110=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon111=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI112=== CONT TestSetClientTLS113=== CONT TestGetStorePathHash114=== RUN TestGetStorePathHash/valid_store_path115=== PAUSE TestGetStorePathHash/valid_store_path116=== RUN TestGetStorePathHash/basename_without_hyphen_should_error117=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error118=== CONT TestScriptTokenBadJSON119=== CONT TestConvertHashToNix32120=== CONT TestScriptTokenEmptyToken121=== CONT TestEncodeNixBase32WithRealHash122--- PASS: TestEncodeNixBase32WithRealHash (0.00s)123=== CONT TestScriptTokenCachesUntilRefresh1242026/10/05 11:22:46 ERROR Upload failed error="bad path" count=3125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestEncodeNixBase32127=== RUN TestEncodeNixBase32/test_string_hash128=== CONT TestFileTokenEmpty129=== CONT TestFileTokenMissing130=== CONT TestRateLimiterFeedback131=== CONT TestParsePathInfoJSON132=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess133=== CONT TestFileTokenReadsAndCaches134=== CONT TestPathInfoCACompatibility135=== CONT TestStaticToken136=== CONT TestParsePathInfoJSONMultiplePaths137=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI138=== CONT TestSetClientTLSErrors139--- PASS: TestResolveStorePath (0.00s)140=== CONT TestShellSplitErrors141=== CONT TestClientSignaturesByStorePath142=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error143=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error144=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error145=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error146--- PASS: TestScriptTokenScriptFails (0.00s)147--- PASS: TestStreamPushIsolatesFailures (0.00s)148--- PASS: TestStaticToken (0.00s)149--- PASS: TestShellSplitErrors (0.00s)150=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512151--- PASS: TestClientSignaturesByStorePath (0.00s)152=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512153=== CONT TestStreamPushRequestLine154=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1552026/10/05 11:22:46 WARN Rate limiter enabled after throttle name=server-test rate=5156=== CONT TestStreamPushReportsEveryPath157=== RUN TestRateLimiterFeedback/429_enables_limiter158=== RUN TestParsePathInfoJSON/Nix_format159=== RUN TestPathInfoCACompatibility/null_ca_field160=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== CONT TestStreamPushReportsSignatures162=== RUN TestConvertHashToNix32/SRI_format_to_Nix32163=== PAUSE TestEncodeNixBase32/test_string_hash164=== CONT TestStreamPushBatchesUnderLoad165=== CONT TestShellSplit1662026/10/05 11:22:46 ERROR Upload failed error=boom count=1167--- PASS: TestFileTokenEmpty (0.00s)168=== CONT TestUploadMultipart_PartsInParallel169=== PAUSE TestRateLimiterFeedback/429_enables_limiter170=== CONT TestStreamPushGivesUpOnDeadServer171=== PAUSE TestParsePathInfoJSON/Nix_format172=== RUN TestSetClientTLSErrors/missing_cert_file173=== RUN TestRateLimiterFeedback/503_enables_limiter174=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32175=== PAUSE TestRateLimiterFeedback/503_enables_limiter176=== CONT TestFilterOversizedClosures177=== CONT TestUploadMultipart_SupersededByPeer1782026/10/05 11:22:46 ERROR Upload failed error="connection refused" count=20179=== RUN TestUploadMultipart_SupersededByPeer/exists1802026/10/05 11:22:46 ERROR Server seems unavailable, giving up on batch untried=17181=== PAUSE TestUploadMultipart_SupersededByPeer/exists182=== RUN TestParsePathInfoJSON/Lix_format183=== CONT TestCaseHackSuffix1842026/10/05 11:22:46 ERROR Upload failed error=boom count=1185=== RUN TestSetClientTLS/rejects_connection_without_client_cert186=== CONT TestPartSizeForNAR187=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert188=== RUN TestFilterOversizedClosures/no_limit_keeps_everything189=== RUN TestPartSizeForNAR/zero_stays_at_minimum190=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum191=== RUN TestConvertHashToNix32/already_Nix32_format192--- PASS: TestFileTokenReadsAndCaches (0.03s)193--- PASS: TestShellSplit (0.00s)194--- PASS: TestScriptTokenEmptyToken (0.03s)195--- PASS: TestScriptTokenBadJSON (0.01s)196--- PASS: TestFileTokenMissing (0.03s)197--- PASS: TestStreamPushReportsEveryPath (0.03s)198--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)199--- PASS: TestDoServerRequestAttachesToken (0.03s)200=== CONT TestDumpPathSingleFile201=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun202=== CONT TestDoWithRetry_BodyReplayedViaGetBody203=== RUN TestEncodeNixBase32/empty_input204=== PAUSE TestEncodeNixBase32/empty_input205=== CONT TestDumpPathMatchesNix206=== CONT TestRegisterUploadedObjectReusesConnections207=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths208=== PAUSE TestPathInfoCACompatibility/null_ca_field209=== PAUSE TestSetClientTLSErrors/missing_cert_file210=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter211=== RUN TestUploadMultipart_SupersededByPeer/missing212=== PAUSE TestParsePathInfoJSON/Lix_format213=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica214=== RUN TestParsePathInfoJSON/empty_input215=== PAUSE TestParsePathInfoJSON/empty_input216=== RUN TestParsePathInfoJSON/whitespace_only217=== PAUSE TestParsePathInfoJSON/whitespace_only218=== RUN TestParsePathInfoJSON/invalid_JSON219=== PAUSE TestParsePathInfoJSON/invalid_JSON220=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA221=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA222=== RUN TestSetClientTLS/preserves_debug_logging_transport223=== PAUSE TestSetClientTLS/preserves_debug_logging_transport224=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything225=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped226=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped227=== RUN TestFilterOversizedClosures/all_closures_skipped2282026/10/05 11:22:46 WARN Rate limiter enabled after throttle name=server-test rate=5229=== PAUSE TestFilterOversizedClosures/all_closures_skipped230=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error2312026/10/05 11:22:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34515232=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error233=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)234=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI235=== CONT TestGetStorePathHash/valid_store_path236=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon237=== CONT TestEncodeNixBase32/test_string_hash238=== CONT TestEncodeNixBase32/empty_input239=== CONT TestParsePathInfoJSON/Nix_format240=== CONT TestSetClientTLS/rejects_connection_without_client_cert241=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512242=== CONT TestParsePathInfoJSON/empty_input243=== CONT TestParsePathInfoJSON/Lix_format244=== CONT TestGetStorePathHash/basename_without_hyphen_should_error245=== CONT TestFilterOversizedClosures/no_limit_keeps_everything246=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths247=== RUN TestPathInfoCACompatibility/old_string_format_-_text248=== PAUSE TestUploadMultipart_SupersededByPeer/missing249=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter250=== RUN TestSetClientTLSErrors/missing_key_file2512026/10/05 11:22:46 WARN Rate limiter backed off name=server-test rate=5252=== RUN TestPartSizeForNAR/small_stays_at_minimum2532026/10/05 11:22:46 INFO Garbage collection started254=== PAUSE TestConvertHashToNix32/already_Nix32_format2552026/10/05 11:22:46 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34515256=== CONT TestParsePathInfoJSON/whitespace_only257=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA258=== PAUSE TestPartSizeForNAR/small_stays_at_minimum259=== RUN TestConvertHashToNix32/invalid_format260=== PAUSE TestConvertHashToNix32/invalid_format261=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2622026/10/05 11:22:46 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=2000263=== CONT TestUploadMultipart_SupersededByPeer/exists264=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum265=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum266=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts267=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts268=== RUN TestPartSizeForNAR/1_TiB269=== PAUSE TestPartSizeForNAR/1_TiB270=== RUN TestPartSizeForNAR/5_TiB_S3_max_object271=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object272=== RUN TestPartSizeForNAR/capped_at_5_GiB273=== PAUSE TestPartSizeForNAR/capped_at_5_GiB274=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text275=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive276=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== RUN TestPathInfoCACompatibility/new_structured_format_-_text278=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text279=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method280=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method281=== CONT TestUploadMultipart_SupersededByPeer/missing2822026/10/05 11:22:46 INFO Garbage collection started283=== CONT TestParsePathInfoJSON/invalid_JSON284=== CONT TestConvertHashToNix32/invalid_format285=== CONT TestConvertHashToNix32/already_Nix32_format2862026/10/05 11:22:46 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=0287=== CONT TestPartSizeForNAR/zero_stays_at_minimum288=== CONT TestPartSizeForNAR/1_TiB289=== CONT TestPathInfoCACompatibility/null_ca_field290=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts291=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum292=== CONT TestPartSizeForNAR/small_stays_at_minimum293=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method294=== CONT TestPathInfoCACompatibility/new_structured_format_-_text295=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive296=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths297=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter298=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter299=== CONT TestPartSizeForNAR/5_TiB_S3_max_object300=== CONT TestRateLimiterFeedback/429_enables_limiter301=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths302=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter303=== CONT TestSetClientTLS/preserves_debug_logging_transport304=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter305=== CONT TestRateLimiterFeedback/503_enables_limiter306=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3072026/10/05 11:22:46 WARN Rate limiter enabled after throttle name=server-test rate=5308=== PAUSE TestSetClientTLSErrors/missing_key_file3092026/10/05 11:22:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:40127310=== RUN TestSetClientTLSErrors/missing_ca_file311=== PAUSE TestSetClientTLSErrors/missing_ca_file312=== RUN TestSetClientTLSErrors/invalid_ca_file313=== PAUSE TestSetClientTLSErrors/invalid_ca_file314=== CONT TestSetClientTLSErrors/missing_cert_file3152026/10/05 11:22:46 WARN Garbage collection finished on another replica. Its statistics are not available here316=== CONT TestFilterOversizedClosures/all_closures_skipped3172026/10/05 11:22:46 WARN Rate limiter enabled after throttle name=server-test rate=5318--- PASS: TestStreamPushReportsSignatures (0.03s)3192026/10/05 11:22:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33407320--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)321=== CONT TestSetClientTLSErrors/invalid_ca_file322=== CONT TestSetClientTLSErrors/missing_ca_file3232026/10/05 11:22:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=503242026/10/05 11:22:46 WARN Rate limiter backed off name=server-test rate=5325=== CONT TestSetClientTLSErrors/missing_key_file3262026/10/05 11:22:46 WARN Rate limiter backed off name=server-test rate=5327=== CONT TestConvertHashToNix32/SRI_format_to_Nix32328=== CONT TestPathInfoCACompatibility/old_string_format_-_text329=== CONT TestPartSizeForNAR/capped_at_5_GiB330--- PASS: TestEncodeNixBase32 (0.03s)331 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)332 --- PASS: TestEncodeNixBase32/empty_input (0.00s)333--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)334--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)335--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)336--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)337--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)338 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)339 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)340--- PASS: TestConvertHashToNix32 (0.03s)341 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)342 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)343 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)344--- PASS: TestGetStorePathHash (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)347 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)348 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)349--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)350 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)351 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)352--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)353--- PASS: TestPathInfoCACompatibility (0.03s)354 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)355 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)356 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)357 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)358 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)359--- PASS: TestPartSizeForNAR (0.00s)360 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)362 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)363 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)365 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)366 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)367--- PASS: TestFilterOversizedClosures (0.00s)368 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)369 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)370 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)371--- PASS: TestPathInfoHashCompatibility (0.01s)372 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)373 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)374 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)375 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)376--- PASS: TestParsePathInfoJSON (0.03s)377 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)378 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)379 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)380 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)381 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)382--- PASS: TestRateLimiterFeedback (0.03s)383 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)384 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)385 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)387--- PASS: TestSetClientTLSErrors (0.03s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3922026/10/05 11:22:46 http: TLS handshake error from 127.0.0.1:34918: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.03s)394 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)398--- PASS: TestStreamPushRequestLine (0.05s)399--- PASS: TestDumpPathSingleFile (0.04s)400--- PASS: TestCaseHackSuffix (0.04s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestDumpPathMatchesNix (0.07s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)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/postgres3101644282/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/postgres3101644282/data -l logfile start434435/build/postgres3101644282:5432 - no response4362026-10-05 11:22:48.673 UTC [131] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-05 11:22:48.673 UTC [131] LOG: listening on Unix socket "/build/postgres3101644282/.s.PGSQL.5432"4382026-10-05 11:22:48.677 UTC [138] LOG: database system was shut down at 2026-10-05 11:22:48 UTC4392026-10-05 11:22:48.681 UTC [131] LOG: database system is ready to accept connections440/build/postgres3101644282: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/05 11:22:49 INFO lead: acquired remote=192.0.2.1:12344872026/10/05 11:22:49 INFO lead: released remote=192.0.2.1:12344882026/10/05 11:22:49 INFO lead: acquired remote=192.0.2.1:12344892026/10/05 11:22:50 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.83s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/05 11:22:50 INFO lead: acquired remote=192.0.2.1:12344972026-10-05 11:22:52.315 UTC [393] FATAL: terminating connection due to administrator command4982026/10/05 11:22:52 INFO lead: acquired remote=192.0.2.1:12344992026/10/05 11:22:53 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/05 11:22:53 INFO lead: released remote=192.0.2.1:12345012026/10/05 11:22:53 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyOutlastsServerWriteTimeout612=== PAUSE TestReadProxyOutlastsServerWriteTimeout613=== RUN TestReadProxyConditionalGet614=== PAUSE TestReadProxyConditionalGet615=== RUN TestReadProxyRootRedirectsToIndexHTML616=== PAUSE TestReadProxyRootRedirectsToIndexHTML617=== RUN TestReadProxyDisabled618=== PAUSE TestReadProxyDisabled619=== RUN TestReadRedirectNar620=== PAUSE TestReadRedirectNar621=== RUN TestReadRedirectKeepsNarinfoProxied622=== PAUSE TestReadRedirectKeepsNarinfoProxied623=== RUN TestReadProxyRangeRequest624=== PAUSE TestReadProxyRangeRequest625=== RUN TestReadRedirectUsesPublicS3URL626=== PAUSE TestReadRedirectUsesPublicS3URL627=== RUN TestPush_OverlappingRootsStoreOneRowPerKey628=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey629=== RUN TestPush_CompleteCommitsEveryRoot630=== PAUSE TestPush_CompleteCommitsEveryRoot631=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit632=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit633=== RUN TestPush_RejectsBadRequests634=== PAUSE TestPush_RejectsBadRequests635=== RUN TestPush_SignsNarinfosOfItsPendingObjects636=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects637=== RUN TestRedundantMultipartUpload638=== PAUSE TestRedundantMultipartUpload639=== RUN TestCompleteMultipartUpload_ErrorButObjectExists640=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists641=== RUN TestCompletedNarNotReofferedAcrossClosures642=== PAUSE TestCompletedNarNotReofferedAcrossClosures643=== RUN TestPresignedUploadRegisteredBeforeCommit644=== PAUSE TestPresignedUploadRegisteredBeforeCommit645=== RUN TestService_Rustfstest646=== PAUSE TestService_Rustfstest647=== RUN TestParseSize648=== PAUSE TestParseSize649=== RUN TestSkippedUploadsHandler650=== PAUSE TestSkippedUploadsHandler651=== RUN TestSystemdListenerNotActivated652--- PASS: TestSystemdListenerNotActivated (0.00s)653=== RUN TestWatchdogBeatsWhenHealthy654--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)655=== RUN TestWatchdogSkipsWhenUnhealthy6562026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/05 11:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"665--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)666=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle668=== RUN TestProxyWriteTimeout669=== PAUSE TestProxyWriteTimeout670=== RUN TestPendingClosureWriteTimeout671=== PAUSE TestPendingClosureWriteTimeout672=== RUN TestIsValidUploadKey673=== PAUSE TestIsValidUploadKey674=== RUN TestUploadHandlersRejectInvalidKeys675=== PAUSE TestUploadHandlersRejectInvalidKeys676=== RUN TestUploadHandlersRejectOversizedBody677=== PAUSE TestUploadHandlersRejectOversizedBody678=== RUN TestService_cleanupPendingClosuresHandler679=== PAUSE TestService_cleanupPendingClosuresHandler680=== RUN TestService_createPendingClosureHandler681=== PAUSE TestService_createPendingClosureHandler682=== RUN TestService_verifyS3Integrity683=== PAUSE TestService_verifyS3Integrity684=== RUN TestCompleteMultipartUnregistered685=== PAUSE TestCompleteMultipartUnregistered686=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT687=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT688=== CONT TestProxyWriteTimeout689=== RUN TestProxyWriteTimeout/narinfo690=== CONT TestService_AuthMiddleware691=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle692=== CONT TestSkippedUploadsHandler693=== CONT TestParseSize694--- PASS: TestParseSize (0.00s)695=== CONT TestReadProxyConditionalGet696=== CONT TestService_Rustfstest697=== CONT TestPresignedUploadRegisteredBeforeCommit698=== CONT TestCompletedNarNotReofferedAcrossClosures6992026/10/05 11:22:53 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000700=== CONT TestCompleteMultipartUpload_ErrorButObjectExists701=== CONT TestRedundantMultipartUpload702=== CONT TestPush_SignsNarinfosOfItsPendingObjects703=== CONT TestPush_RejectsBadRequests704=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit705=== CONT TestPush_CompleteCommitsEveryRoot706=== CONT TestPush_OverlappingRootsStoreOneRowPerKey707=== CONT TestReadRedirectUsesPublicS3URL708=== CONT TestReadProxyRangeRequest709=== CONT TestReadRedirectKeepsNarinfoProxied710=== CONT TestService_cleanupPendingClosuresHandler711=== CONT TestReadRedirectNar712=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT713=== CONT TestReadProxyDisabled714=== CONT TestReadProxyRootRedirectsToIndexHTML715=== CONT TestCompleteMultipartUnregistered716=== PAUSE TestProxyWriteTimeout/narinfo717=== RUN TestProxyWriteTimeout/1_GiB_nar718=== PAUSE TestProxyWriteTimeout/1_GiB_nar719=== RUN TestProxyWriteTimeout/10_GiB_nar720=== PAUSE TestProxyWriteTimeout/10_GiB_nar721=== RUN TestProxyWriteTimeout/unknown_size722=== PAUSE TestProxyWriteTimeout/unknown_size723=== CONT TestService_verifyS3Integrity724--- PASS: TestSkippedUploadsHandler (0.01s)725=== CONT TestPushWaitsForSweepHoldingRow726--- PASS: TestService_Rustfstest (0.27s)727=== CONT TestService_createPendingClosureHandler7282026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures729--- PASS: TestReadProxyConditionalGet (0.33s)730=== CONT TestSweepRechecksPendingAfterLocking731--- PASS: TestReadProxyDisabled (0.32s)732=== CONT TestMultipartCleanup7332026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures7342026/10/05 11:22:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7352026/10/05 11:22:54 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"736--- PASS: TestService_AuthMiddleware (0.37s)737=== CONT TestGetExistingObjectsLocksRows7382026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures7392026/10/05 11:22:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7402026/10/05 11:22:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LmFmNmYwYWJkLWUyYmMtNDJjMC04ODMxLWY0ZDhjZmFjOWUzOXgxNzkxMTk5Mzc0MzMxMDEwOTYw741--- PASS: TestReadRedirectUsesPublicS3URL (0.41s)742=== CONT TestRegisterCompletedObjectNeedsPendingRow7432026/10/05 11:22:54 INFO Received push request method=POST path=/api/pushes7442026/10/05 11:22:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LmFmNmYwYWJkLWUyYmMtNDJjMC04ODMxLWY0ZDhjZmFjOWUzOXgxNzkxMTk5Mzc0MzMxMDEwOTYw parts=1745--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.42s)746=== CONT TestReadProxyOutlastsServerWriteTimeout7472026/10/05 11:22:54 INFO Received complete push request method=POST path=/api/pushes/1/complete7482026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures7492026/10/05 11:22:54 INFO Received push request method=POST path=/api/pushes7502026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures751=== RUN TestPush_RejectsBadRequests/no_roots752=== PAUSE TestPush_RejectsBadRequests/no_roots753=== RUN TestPush_RejectsBadRequests/no_objects754=== PAUSE TestPush_RejectsBadRequests/no_objects755=== RUN TestPush_RejectsBadRequests/bad_root756=== PAUSE TestPush_RejectsBadRequests/bad_root757=== RUN TestPush_RejectsBadRequests/root_not_in_objects758=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects759=== CONT TestSweepSkipsRowsLockedByPush7602026/10/05 11:22:54 INFO Received push request method=POST path=/api/pushes7612026/10/05 11:22:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7622026/10/05 11:22:54 INFO Signed narinfos id=1 count=1763--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.50s)764=== CONT TestReadProxyHead7652026/10/05 11:22:54 INFO Received push request method=POST path=/api/pushes7662026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=07672026/10/05 11:22:54 WARN Force mode enabled - objects will be deleted immediately without grace period768--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.52s)769=== CONT TestFailedS3DeleteKeepsTombstone7702026/10/05 11:22:54 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=07712026/10/05 11:22:54 INFO Vacuumed table table=pending_closures7722026/10/05 11:22:54 INFO Received push request method=POST path=/api/pushes7732026/10/05 11:22:54 INFO Vacuumed table table=pending_objects7742026/10/05 11:22:54 INFO Vacuumed table table=multipart_uploads7752026/10/05 11:22:54 INFO Vacuumed table table=closures7762026/10/05 11:22:54 INFO Vacuumed table table=objects7772026/10/05 11:22:54 INFO Received complete push request method=POST path=/api/pushes/2/complete778--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.54s)779=== CONT TestReadProxyInvalidPath7802026/10/05 11:22:54 INFO Received complete push request method=POST path=/api/pushes/1/complete781--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.55s)782=== CONT TestForceGCDuringPushOffersSweptObject783=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows784=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows785=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check786=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check787=== CONT TestReadProxy404788--- PASS: TestPush_CompleteCommitsEveryRoot (0.55s)789=== CONT TestCommitRacingPendingCleanupKeepsObjects7902026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures7912026/10/05 11:22:54 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7922026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures793--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.59s)794=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection795--- PASS: TestReadRedirectNar (0.60s)796=== CONT TestServerTLSConfig797=== RUN TestServerTLSConfig/no_client_CA798=== PAUSE TestServerTLSConfig/no_client_CA799=== RUN TestServerTLSConfig/missing_CA_file800=== PAUSE TestServerTLSConfig/missing_CA_file801=== RUN TestServerTLSConfig/not_a_PEM_file802=== PAUSE TestServerTLSConfig/not_a_PEM_file803=== CONT TestService_NativeMTLS8042026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures805--- PASS: TestReadProxyRangeRequest (0.65s)806=== CONT TestMetricsInventory8072026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8082026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures809--- PASS: TestReadRedirectKeepsNarinfoProxied (0.70s)810=== CONT TestGCSweepDeliversEachKeyOnce811--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.71s)812=== CONT TestNARDeduplicationMetadataUploadBug8132026/10/05 11:22:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8142026/10/05 11:22:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8152026/10/05 11:22:54 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst816--- PASS: TestCompleteMultipartUnregistered (0.72s)817=== CONT TestTombstonedObjectOfferedWithoutWaiting8182026/10/05 11:22:54 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LjBjNDI1YjJlLWQyN2YtNDVmMC1iNzYyLWE0YTk3ODBlYTMwMngxNzkxMTk5Mzc0MzAwMzk3Mzg4 parts=128192026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures820--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.74s)821=== CONT TestReadProxyNarStreaming8222026/10/05 11:22:54 INFO Received cleanup request method=DELETE path=/api/pending_closures8232026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=08242026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8252026/10/05 11:22:54 INFO Received cleanup request method=DELETE path=/api/pending_closures8262026/10/05 11:22:54 INFO Aborted multipart uploads count=1 kept=08272026/10/05 11:22:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8282026-10-05 11:22:54.704 UTC [486] ERROR: Closure does not exist: id=18292026-10-05 11:22:54.704 UTC [486] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8302026-10-05 11:22:54.704 UTC [486] STATEMENT: -- name: CommitPendingClosure :exec831 SELECT commit_pending_closure($1::bigint)832 833--- PASS: TestService_cleanupPendingClosuresHandler (0.76s)834=== CONT TestCreatePendingClosureRejectsOversizedNAR8352026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures836--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)837=== CONT TestGCSweepSkipsPendingObjects8382026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8392026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8402026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8412026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8422026/10/05 11:22:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8432026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=08442026/10/05 11:22:54 WARN Force mode enabled - objects will be deleted immediately without grace period8452026/10/05 11:22:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LmMwZTE3OGYxLTZmMGUtNGJkZC1iOWM1LThhZDRhZWNkNzZlNHgxNzkxMTk5Mzc0Mzg4MTg0MDg4 parts=128462026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8472026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures848--- PASS: TestGetExistingObjectsLocksRows (0.48s)849=== CONT TestReadProxyNarinfoAlreadyDecompressed8502026/10/05 11:22:54 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=08512026/10/05 11:22:54 INFO Vacuumed table table=pending_closures8522026/10/05 11:22:54 INFO Vacuumed table table=pending_objects8532026/10/05 11:22:54 INFO Vacuumed table table=multipart_uploads8542026/10/05 11:22:54 INFO Vacuumed table table=closures8552026/10/05 11:22:54 INFO Vacuumed table table=objects856--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)857=== CONT TestCacheConfigHandlerMaxNarSize858--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)859=== CONT TestDeduplicatedObjectsRecordedAsPending860--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.44s)861=== CONT TestReadProxyNarinfo8622026/10/05 11:22:54 INFO Received cleanup request method=DELETE path=/api/pending_closures8632026/10/05 11:22:54 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket28/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8642026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=18652026/10/05 11:22:54 INFO Received cleanup request method=DELETE path=/api/pending_closures8662026/10/05 11:22:54 INFO Aborted multipart uploads count=1 kept=08672026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=0868--- PASS: TestReadProxyHead (0.42s)869=== CONT TestGenerateLandingPage870--- PASS: TestGenerateLandingPage (0.00s)871=== CONT TestPushDedupSurvivesConcurrentGC8722026/10/05 11:22:54 WARN Force mode enabled - objects will be deleted immediately without grace period8732026/10/05 11:22:54 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=08742026/10/05 11:22:54 INFO Vacuumed table table=pending_closures875--- PASS: TestMultipartCleanup (0.60s)876=== CONT TestService_readinessHandler8772026/10/05 11:22:54 INFO Vacuumed table table=pending_objects8782026/10/05 11:22:54 INFO Vacuumed table table=multipart_uploads8792026/10/05 11:22:54 INFO Vacuumed table table=closures8802026/10/05 11:22:54 INFO Vacuumed table table=objects8812026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures8822026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=08832026/10/05 11:22:54 WARN Force mode enabled - objects will be deleted immediately without grace period8842026/10/05 11:22:54 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=08852026/10/05 11:22:54 INFO Vacuumed table table=pending_closures8862026/10/05 11:22:54 INFO Vacuumed table table=pending_objects8872026/10/05 11:22:54 INFO Vacuumed table table=multipart_uploads8882026/10/05 11:22:54 INFO Vacuumed table table=closures8892026/10/05 11:22:54 INFO Vacuumed table table=objects890--- PASS: TestSweepSkipsRowsLockedByPush (0.49s)891=== CONT TestService_healthCheckHandler892--- PASS: TestReadProxyInvalidPath (0.41s)893=== CONT TestIsValidCachePath894=== RUN TestIsValidCachePath/narinfo895=== PAUSE TestIsValidCachePath/narinfo896=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars897=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars898=== RUN TestIsValidCachePath/nar_zst899=== PAUSE TestIsValidCachePath/nar_zst900=== RUN TestIsValidCachePath/nar_xz901=== PAUSE TestIsValidCachePath/nar_xz902=== RUN TestIsValidCachePath/nar_bz2903=== PAUSE TestIsValidCachePath/nar_bz2904=== RUN TestIsValidCachePath/nar_uncompressed905=== PAUSE TestIsValidCachePath/nar_uncompressed906=== RUN TestIsValidCachePath/ls907=== PAUSE TestIsValidCachePath/ls908=== RUN TestIsValidCachePath/log909=== PAUSE TestIsValidCachePath/log910=== RUN TestIsValidCachePath/realisation911=== PAUSE TestIsValidCachePath/realisation912=== RUN TestIsValidCachePath/nix-cache-info913=== PAUSE TestIsValidCachePath/nix-cache-info914=== RUN TestIsValidCachePath/index.html915=== PAUSE TestIsValidCachePath/index.html916=== RUN TestIsValidCachePath/traversal_parent917=== PAUSE TestIsValidCachePath/traversal_parent918=== RUN TestIsValidCachePath/traversal_in_middle919=== PAUSE TestIsValidCachePath/traversal_in_middle920=== RUN TestIsValidCachePath/invalid_char_e921=== PAUSE TestIsValidCachePath/invalid_char_e922=== RUN TestIsValidCachePath/invalid_char_u923=== PAUSE TestIsValidCachePath/invalid_char_u924=== RUN TestIsValidCachePath/random_path925=== PAUSE TestIsValidCachePath/random_path926=== RUN TestIsValidCachePath/empty927=== PAUSE TestIsValidCachePath/empty928=== RUN TestIsValidCachePath/leading_slash929=== PAUSE TestIsValidCachePath/leading_slash930=== RUN TestIsValidCachePath/wrong_extension931=== PAUSE TestIsValidCachePath/wrong_extension932=== RUN TestIsValidCachePath/short_hash933=== PAUSE TestIsValidCachePath/short_hash934=== CONT TestGracefulShutdownDrainsInflight9352026/10/05 11:22:54 INFO Starting HTTP server address=127.0.0.1:389519362026/10/05 11:22:54 INFO Shutdown signal received, draining in-flight requests timeout=10s9372026/10/05 11:22:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9382026/10/05 11:22:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LjM0YWQyMjc5LWJjMGQtNDBiMS1hNmE1LTVlNmNkODU3MzhlNXgxNzkxMTk5Mzc0NjA3NDgyNTE4 parts=109392026/10/05 11:22:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9402026/10/05 11:22:54 INFO Completed upload id=19412026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures9422026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures9432026/10/05 11:22:54 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9442026/10/05 11:22:54 WARN Found objects in DB but missing from S3, will re-upload count=1945--- PASS: TestService_verifyS3Integrity (0.99s)946=== CONT TestGCTaskStore_Fail947--- PASS: TestGCTaskStore_Fail (0.00s)948=== CONT TestGCTaskStore_PhaseUpdates949--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)950=== CONT TestGCTaskStore_CompletedAllowsNewTask951--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)952=== CONT TestGCTaskStore_GetReturnsLatest953--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)954=== CONT TestGCTaskStore_GetEmpty955--- PASS: TestGCTaskStore_GetEmpty (0.00s)956=== CONT TestGCTaskStore_ConflictDifferentParams957--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)958=== CONT TestProxyHeadersOnlyTrustedOnSocket9592026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=09602026/10/05 11:22:54 INFO Aborted multipart uploads count=0 kept=09612026/10/05 11:22:54 WARN Force mode enabled - objects will be deleted immediately without grace period9622026/10/05 11:22:54 WARN Force mode enabled - objects will be deleted immediately without grace period9632026/10/05 11:22:54 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=09642026/10/05 11:22:54 INFO Vacuumed table table=pending_closures965--- PASS: TestReadProxy404 (0.46s)966=== CONT TestGCTaskStore_DeduplicateSameParams967--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)968=== CONT TestParseSingleRange969=== RUN TestParseSingleRange/none970=== PAUSE TestParseSingleRange/none971=== RUN TestParseSingleRange/unknown_unit972=== PAUSE TestParseSingleRange/unknown_unit973=== RUN TestParseSingleRange/multi-range_ignored974=== PAUSE TestParseSingleRange/multi-range_ignored975=== RUN TestParseSingleRange/malformed_no_dash976=== PAUSE TestParseSingleRange/malformed_no_dash977=== RUN TestParseSingleRange/malformed_both_empty978=== PAUSE TestParseSingleRange/malformed_both_empty979=== RUN TestParseSingleRange/malformed_end_before_start980=== PAUSE TestParseSingleRange/malformed_end_before_start981=== RUN TestParseSingleRange/closed982=== PAUSE TestParseSingleRange/closed983=== RUN TestParseSingleRange/open-ended984=== PAUSE TestParseSingleRange/open-ended985=== RUN TestParseSingleRange/end_clamped_to_size986=== PAUSE TestParseSingleRange/end_clamped_to_size987=== RUN TestParseSingleRange/suffix988=== PAUSE TestParseSingleRange/suffix989=== RUN TestParseSingleRange/suffix_exceeds_size990=== PAUSE TestParseSingleRange/suffix_exceeds_size991=== RUN TestParseSingleRange/single_byte992=== PAUSE TestParseSingleRange/single_byte993=== RUN TestParseSingleRange/start_past_EOF994=== PAUSE TestParseSingleRange/start_past_EOF995=== RUN TestParseSingleRange/start_far_past_EOF996=== PAUSE TestParseSingleRange/start_far_past_EOF997=== CONT TestGCTaskStore_StartNew998--- PASS: TestGCTaskStore_StartNew (0.00s)999=== CONT TestGCEndsOnShutdown1000=== RUN TestGCEndsOnShutdown/before_the_run1001=== PAUSE TestGCEndsOnShutdown/before_the_run1002=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1003=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1004=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1005=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1006=== CONT TestPresentNotReportedWhileGCDeletesClosure1007--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1008=== CONT TestPresentReportsOnlyClosureRoots10092026/10/05 11:22:54 INFO Received uploads request method=POST path=/api/pending_closures10102026/10/05 11:22:54 INFO Vacuumed table table=pending_objects10112026/10/05 11:22:54 INFO Vacuumed table table=multipart_uploads10122026/10/05 11:22:54 INFO Vacuumed table table=closures10132026/10/05 11:22:54 INFO Vacuumed table table=objects10142026/10/05 11:22:54 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10152026/10/05 11:22:54 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1016--- PASS: TestFailedS3DeleteKeepsTombstone (0.51s)1017=== CONT TestCreatePin_ReservedPins1018--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.48s)1019=== CONT TestGCMetrics10202026/10/05 11:22:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10212026/10/05 11:22:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1022--- PASS: TestService_NativeMTLS (0.44s)1023=== CONT TestClientWithDependencies10242026/10/05 11:22:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1025--- PASS: TestMetricsInventory (0.43s)1026=== CONT TestOrphanedObjectsGCStressTest10272026/10/05 11:22:55 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LmVhOTVjMDdmLTM3YzAtNDU0Ny1hZTliLWI2MDMyOTFjMDBlM3gxNzkxMTk5Mzc0NzE3Njg5ODM5 parts=1010282026/10/05 11:22:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10292026/10/05 11:22:55 INFO Completed upload id=110302026/10/05 11:22:55 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010312026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures10322026/10/05 11:22:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures10332026/10/05 11:22:55 INFO Aborted multipart uploads count=0 kept=010342026/10/05 11:22:55 INFO Aborted multipart uploads count=0 kept=010352026/10/05 11:22:55 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=010362026/10/05 11:22:55 WARN Force mode enabled - objects will be deleted immediately without grace period1037--- PASS: TestPushWaitsForSweepHoldingRow (1.12s)1038=== CONT TestClientMultipleUploads10392026/10/05 11:22:55 INFO Vacuumed table table=pending_closures10402026/10/05 11:22:55 INFO Vacuumed table table=pending_objects10412026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures10422026/10/05 11:22:55 INFO Vacuumed table table=multipart_uploads10432026/10/05 11:22:55 INFO Vacuumed table table=closures10442026/10/05 11:22:55 INFO Vacuumed table table=objects1045--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.42s)1046=== CONT TestGCBugBareHashReferences10472026/10/05 11:22:55 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=010482026/10/05 11:22:55 INFO Vacuumed table table=pending_closures10492026/10/05 11:22:55 INFO Vacuumed table table=pending_objects10502026/10/05 11:22:55 INFO Vacuumed table table=multipart_uploads10512026/10/05 11:22:55 INFO Vacuumed table table=closures10522026/10/05 11:22:55 INFO Vacuumed table table=objects1053--- PASS: TestGCSweepDeliversEachKeyOnce (0.45s)1054=== CONT TestOrphanedObjectsGC1055=== NAME TestNARDeduplicationMetadataUploadBug1056 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3579177703/001/store/rx99gcapq19q3v2clq79b3h7mqckg0sb-file1.txt10572026/10/05 11:22:55 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001058--- PASS: TestService_createPendingClosureHandler (0.89s)1059=== CONT TestClientIntegration1060--- PASS: TestReadProxyNarStreaming (0.42s)1061=== CONT TestGCAdvisoryLockBlocksConcurrentRun10622026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures10632026/10/05 11:22:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1064--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.35s)1065=== CONT TestClientErrorHandling1066=== RUN TestClientErrorHandling/InvalidStorePath1067=== PAUSE TestClientErrorHandling/InvalidStorePath1068=== RUN TestClientErrorHandling/InvalidAuthToken10692026/10/05 11:22:55 INFO Aborted multipart uploads count=0 kept=01070=== PAUSE TestClientErrorHandling/InvalidAuthToken1071=== RUN TestClientErrorHandling/ServerNotAvailable1072=== PAUSE TestClientErrorHandling/ServerNotAvailable1073=== CONT TestLeadEndsOnShutdown10742026/10/05 11:22:55 WARN Force mode enabled - objects will be deleted immediately without grace period10752026/10/05 11:22:55 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LmMwZDI2ZTNhLWZlZmUtNGRmNi04ZmNiLWE0OWVlZGQ4NjMyMngxNzkxMTk5Mzc0NzkzMTA5OTY5 error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10762026/10/05 11:22:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2QzYmNmYzEtMmJhYi00YWNkLWI0MDEtOTU3YmM4N2UyYmQ1LmZlNDdiNjlhLTk2ZWQtNGQzMi1iYjYzLTMwZGUzZGQ1MWM2ZHgxNzkxMTk5Mzc0Nzg3MzQyMjM4 parts=1210772026/10/05 11:22:55 INFO Received cleanup request method=DELETE path=/api/pending_closures10782026/10/05 11:22:55 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=010792026/10/05 11:22:55 INFO Aborted multipart uploads count=1 kept=010802026/10/05 11:22:55 INFO Vacuumed table table=pending_closures10812026/10/05 11:22:55 INFO Vacuumed table table=pending_objects1082--- PASS: TestRedundantMultipartUpload (1.22s)10832026/10/05 11:22:55 INFO Vacuumed table table=multipart_uploads1084=== CONT TestUploadHandlersRejectInvalidKeys1085=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1086=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1087=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1088=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1089=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1090=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1091=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1092=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1093=== CONT TestClientCADerivations10942026/10/05 11:22:55 INFO Vacuumed table table=closures10952026/10/05 11:22:55 INFO Vacuumed table table=objects10962026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures10972026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes1098--- PASS: TestGCSweepSkipsPendingObjects (0.47s)1099=== CONT TestUploadHandlersRejectOversizedBody1100--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.64s)11012026/10/05 11:22:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1102=== CONT TestLeadIncumbentAnnouncesAtOnce11032026/10/05 11:22:55 INFO Uploading rx99gcapq19q3v2clq79b3h7mqckg0sb-file1.txt (160B)1104--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.38s)1105=== CONT TestCacheStatsHandler11062026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11072026/10/05 11:22:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11082026/10/05 11:22:55 WARN Failed to register uploaded object key=rx99gcapq19q3v2clq79b3h7mqckg0sb.ls error="server returned 404: 404 page not found\n"11092026/10/05 11:22:55 INFO Signed narinfos id=1 count=111102026/10/05 11:22:55 INFO Uploading 1 narinfos11112026/10/05 11:22:55 INFO Received complete push request method=POST path=/api/pushes/1/complete11122026/10/05 11:22:55 WARN Failed to register uploaded object key=rx99gcapq19q3v2clq79b3h7mqckg0sb.narinfo error="server returned 404: 404 page not found\n"11132026/10/05 11:22:55 INFO Upload complete. (64ms)1114=== NAME TestNARDeduplicationMetadataUploadBug1115 metadata_upload_test.go:54: Retrieved narinfo from S3:1116 StorePath: /build/TestNARDeduplicationMetadataUploadBug3579177703/001/store/rx99gcapq19q3v2clq79b3h7mqckg0sb-file1.txt1117 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1118 Compression: zstd1119 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1120 NarSize: 1601121 References: 1122 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1123 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1124 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1125 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11262026/10/05 11:22:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46525/oidc11272026/10/05 11:22:55 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"11282026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures11292026/10/05 11:22:55 WARN readiness check failed error="closed pool"1130--- PASS: TestService_readinessHandler (0.36s)1131=== CONT TestService_ReadScope_PublicByDefault1132=== NAME TestNARDeduplicationMetadataUploadBug1133 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3579177703/001/store/08xs24n3aa2i1fzhiznwfsj3x6n94mjr-file2.txt1134=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1135=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1136=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1137=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1138=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1139=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1140=== CONT TestLeadElectsOneAndHandsOver1141--- PASS: TestService_healthCheckHandler (0.43s)1142=== CONT TestService_ReadAuthMiddleware11432026/10/05 11:22:55 INFO Aborted multipart uploads count=0 kept=011442026/10/05 11:22:55 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=011452026/10/05 11:22:55 INFO Vacuumed table table=pending_closures11462026/10/05 11:22:55 INFO Vacuumed table table=pending_objects11472026/10/05 11:22:55 INFO Vacuumed table table=multipart_uploads11482026/10/05 11:22:55 INFO Starting HTTP server address=127.0.0.1:3915911492026/10/05 11:22:55 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2577416742/001/proxy.sock11502026/10/05 11:22:55 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11512026/10/05 11:22:55 INFO Vacuumed table table=closures11522026/10/05 11:22:55 INFO Shutdown signal received, draining in-flight requests timeout=10s1153--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.42s)1154=== CONT TestService_AuthMiddleware_OIDC11552026/10/05 11:22:55 INFO Vacuumed table table=objects11562026/10/05 11:22:55 INFO Aborted multipart uploads count=0 kept=011572026/10/05 11:22:55 WARN Force mode enabled - objects will be deleted immediately without grace period11582026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes11592026/10/05 11:22:55 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=011602026/10/05 11:22:55 INFO Vacuumed table table=pending_closures11612026/10/05 11:22:55 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11622026/10/05 11:22:55 INFO Vacuumed table table=pending_objects11632026/10/05 11:22:55 INFO Vacuumed table table=multipart_uploads11642026/10/05 11:22:55 INFO Vacuumed table table=closures11652026/10/05 11:22:55 INFO Vacuumed table table=objects1166--- PASS: TestPushDedupSurvivesConcurrentGC (0.51s)1167=== CONT TestConnectWaitsForAPeerMigration11682026/10/05 11:22:55 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11692026/10/05 11:22:55 WARN Failed to register uploaded object key=08xs24n3aa2i1fzhiznwfsj3x6n94mjr.ls error="server returned 404: 404 page not found\n"11702026/10/05 11:22:55 INFO Signed narinfos id=2 count=111712026/10/05 11:22:55 INFO Uploading 1 narinfos11722026/10/05 11:22:55 INFO Received complete push request method=POST path=/api/pushes/2/complete11732026/10/05 11:22:55 WARN Failed to register uploaded object key=08xs24n3aa2i1fzhiznwfsj3x6n94mjr.narinfo error="server returned 404: 404 page not found\n"11742026/10/05 11:22:55 INFO Upload complete. (51ms)1175=== NAME TestNARDeduplicationMetadataUploadBug1176 metadata_upload_test.go:76: Retrieved narinfo from S3:1177 StorePath: /build/TestNARDeduplicationMetadataUploadBug3579177703/001/store/08xs24n3aa2i1fzhiznwfsj3x6n94mjr-file2.txt1178 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1179 Compression: zstd1180 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1181 NarSize: 1601182 References: 1183 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1184 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1185 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1186 {"version":1,"root":{"type":"regular","size":44}}1187--- PASS: TestNARDeduplicationMetadataUploadBug (0.73s)1188=== CONT TestCacheConfigHandler1189=== RUN TestCacheConfigHandler/full_config,_no_issuer1190=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1191=== RUN TestCacheConfigHandler/no_cache_url_configured1192=== PAUSE TestCacheConfigHandler/no_cache_url_configured1193=== RUN TestCacheConfigHandler/no_signing_keys1194=== PAUSE TestCacheConfigHandler/no_signing_keys1195=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1196=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1197=== CONT TestService_RequireScope_OIDC1198--- PASS: TestPresentReportsOnlyClosureRoots (0.44s)1199=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12002026/10/05 11:22:55 INFO Aborted multipart uploads count=0 kept=012012026/10/05 11:22:55 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161202--- PASS: TestReadProxyNarinfo (0.63s)1203=== CONT TestClientPushesUseOnePush12042026/10/05 11:22:55 WARN Force mode enabled - objects will be deleted immediately without grace period12052026/10/05 11:22:55 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=012062026/10/05 11:22:55 INFO Vacuumed table table=pending_closures12072026/10/05 11:22:55 INFO Vacuumed table table=pending_objects12082026/10/05 11:22:55 INFO Vacuumed table table=multipart_uploads12092026/10/05 11:22:55 INFO Vacuumed table table=closures12102026/10/05 11:22:55 INFO Vacuumed table table=objects12112026/10/05 11:22:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44673/oidc1212--- PASS: TestGCMetrics (0.47s)1213=== CONT TestService_AuthMiddleware_MTLSProxyHeader1214=== NAME TestClientMultipleUploads1215 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3161923086/001/store/l7wajgzdp72rw9h38w0hhzhbbnaf64xj-test-file-0.txt1216=== NAME TestClientWithDependencies1217 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1526545748/001/store/hwkx667czgqpgrxdjwbp2q9bl6c5xj0i-test-script12182026/10/05 11:22:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42939/oidc1219=== NAME TestClientMultipleUploads1220 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3161923086/001/store/8sv32cf3bqcaazzvz8vlz5yykj63vb42-test-file-1.txt1221=== NAME TestClientWithDependencies1222 client_integration_test.go:615: Found 1 dependencies (including self)12232026/10/05 11:22:55 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"1224--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.47s)1225=== CONT TestPendingCleanupUsesOneCutoff1226=== NAME TestClientIntegration1227 client_integration_test.go:286: Created store path: /build/TestClientIntegration4237300401/002/store/hirxkj033sqy5nhyhf3qkja2n2yrxlsd-test-file.txt1228=== NAME TestClientMultipleUploads1229 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3161923086/001/store/z2a4h5daqcps4lc1fdylm28pcvy64j51-test-file-2.txt12302026/10/05 11:22:55 INFO lead: acquired remote=192.0.2.1:123412312026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes1232--- PASS: TestService_ReadScope_PublicByDefault (0.39s)1233=== CONT TestResolveDBConnectionString1234=== RUN TestResolveDBConnectionString/flag_wins1235=== PAUSE TestResolveDBConnectionString/flag_wins1236=== RUN TestResolveDBConnectionString/file_when_flag_empty1237=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1238=== RUN TestResolveDBConnectionString/missing_file_is_an_error1239=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1240=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1241=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1242=== RUN TestResolveDBConnectionString/nothing_configured1243=== PAUSE TestResolveDBConnectionString/nothing_configured1244=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12452026/10/05 11:22:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12462026/10/05 11:22:55 INFO Uploading hwkx667czgqpgrxdjwbp2q9bl6c5xj0i-test-script (136B)12472026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12482026/10/05 11:22:55 WARN Failed to register uploaded object key=hwkx667czgqpgrxdjwbp2q9bl6c5xj0i.ls error="server returned 404: 404 page not found\n"12492026/10/05 11:22:55 WARN Failed to register uploaded object key=log/8d7bbm41z1ans2jwdwiipvwbyji7bdk9-test-script.drv error="server returned 404: 404 page not found\n"12502026/10/05 11:22:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12512026/10/05 11:22:55 INFO Signed narinfos id=1 count=112522026/10/05 11:22:55 INFO Uploading 1 narinfos12532026/10/05 11:22:55 INFO Received complete push request method=POST path=/api/pushes/1/complete12542026/10/05 11:22:55 WARN Failed to register uploaded object key=hwkx667czgqpgrxdjwbp2q9bl6c5xj0i.narinfo error="server returned 404: 404 page not found\n"12552026/10/05 11:22:55 INFO Upload complete. (58ms)1256=== NAME TestClientWithDependencies1257 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1526545748/001/store) requires matching store prefix12582026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes12592026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes1260--- PASS: TestClientWithDependencies (0.66s)1261=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1262--- PASS: TestCacheStatsHandler (0.47s)1263=== CONT TestClientFallsBackToClosures12642026/10/05 11:22:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12652026/10/05 11:22:55 INFO Uploading hirxkj033sqy5nhyhf3qkja2n2yrxlsd-test-file.txt (152B)12662026/10/05 11:22:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12672026/10/05 11:22:55 INFO Uploading 8sv32cf3bqcaazzvz8vlz5yykj63vb42-test-file-1.txt (160B)12682026/10/05 11:22:55 INFO Uploading z2a4h5daqcps4lc1fdylm28pcvy64j51-test-file-2.txt (160B)12692026/10/05 11:22:55 INFO Uploading l7wajgzdp72rw9h38w0hhzhbbnaf64xj-test-file-0.txt (160B)12702026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12712026/10/05 11:22:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12722026/10/05 11:22:55 WARN Failed to register uploaded object key=hirxkj033sqy5nhyhf3qkja2n2yrxlsd.ls error="server returned 404: 404 page not found\n"12732026/10/05 11:22:55 INFO Signed narinfos id=1 count=112742026/10/05 11:22:55 INFO Uploading 1 narinfos12752026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12762026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12772026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12782026/10/05 11:22:55 WARN Failed to register uploaded object key=l7wajgzdp72rw9h38w0hhzhbbnaf64xj.ls error="server returned 404: 404 page not found\n"12792026/10/05 11:22:55 INFO lead: acquired remote=192.0.2.1:123412802026/10/05 11:22:55 INFO lead: released remote=192.0.2.1:12341281--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.48s)1282=== CONT TestPinProtectsFromGC12832026/10/05 11:22:55 WARN Failed to register uploaded object key=8sv32cf3bqcaazzvz8vlz5yykj63vb42.ls error="server returned 404: 404 page not found\n"12842026/10/05 11:22:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12852026/10/05 11:22:55 WARN Failed to register uploaded object key=z2a4h5daqcps4lc1fdylm28pcvy64j51.ls error="server returned 404: 404 page not found\n"12862026/10/05 11:22:55 INFO Signed narinfos id=1 count=312872026/10/05 11:22:55 INFO Uploading 3 narinfos12882026/10/05 11:22:55 INFO Received complete push request method=POST path=/api/pushes/1/complete12892026/10/05 11:22:55 WARN Failed to register uploaded object key=hirxkj033sqy5nhyhf3qkja2n2yrxlsd.narinfo error="server returned 404: 404 page not found\n"12902026/10/05 11:22:55 WARN Failed to register uploaded object key=8sv32cf3bqcaazzvz8vlz5yykj63vb42.narinfo error="server returned 404: 404 page not found\n"12912026/10/05 11:22:55 INFO Received complete push request method=POST path=/api/pushes/1/complete12922026/10/05 11:22:55 WARN Failed to register uploaded object key=l7wajgzdp72rw9h38w0hhzhbbnaf64xj.narinfo error="server returned 404: 404 page not found\n"12932026/10/05 11:22:55 WARN Failed to register uploaded object key=z2a4h5daqcps4lc1fdylm28pcvy64j51.narinfo error="server returned 404: 404 page not found\n"12942026/10/05 11:22:55 INFO Upload complete. (58ms)12952026/10/05 11:22:55 INFO Upload complete. (60ms)1296=== NAME TestClientMultipleUploads1297 client_integration_test.go:369: Uploaded 3 paths in 88.234164ms1298--- PASS: TestClientMultipleUploads (0.61s)1299=== CONT TestClientSharedPathCommittedMidPush1300=== NAME TestClientCADerivations1301 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2941216553/001/store/ribim32y6516ngkfsbnk00x33pfv37j6-ca-test13022026/10/05 11:22:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13032026/10/05 11:22:55 WARN Refused reserved pin name=worker-x86_64-linux13042026/10/05 11:22:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13052026/10/05 11:22:55 INFO Received create pin request method=POST path=/api/pins/my-app13062026/10/05 11:22:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1307--- PASS: TestCreatePin_ReservedPins (0.72s)1308=== CONT TestPendingClosureWriteTimeout1309=== RUN TestPendingClosureWriteTimeout/empty1310=== PAUSE TestPendingClosureWriteTimeout/empty1311=== RUN TestPendingClosureWriteTimeout/400_objects1312=== PAUSE TestPendingClosureWriteTimeout/400_objects1313=== RUN TestPendingClosureWriteTimeout/670k_objects1314=== PAUSE TestPendingClosureWriteTimeout/670k_objects1315=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1316=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1317=== CONT TestObjectStatsTrigger1318--- PASS: TestService_ReadAuthMiddleware (0.37s)1319=== CONT TestIsValidUploadKey1320=== RUN TestIsValidUploadKey/narinfo1321=== PAUSE TestIsValidUploadKey/narinfo1322=== RUN TestIsValidUploadKey/nar_zst1323=== PAUSE TestIsValidUploadKey/nar_zst1324=== RUN TestIsValidUploadKey/nar_xz1325=== PAUSE TestIsValidUploadKey/nar_xz1326=== RUN TestIsValidUploadKey/nar_plain1327=== PAUSE TestIsValidUploadKey/nar_plain1328=== RUN TestIsValidUploadKey/listing1329=== PAUSE TestIsValidUploadKey/listing1330=== RUN TestIsValidUploadKey/build_log1331=== PAUSE TestIsValidUploadKey/build_log1332=== RUN TestIsValidUploadKey/build_log_home-manager_file1333=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1334=== RUN TestIsValidUploadKey/build_log_plus_in_name1335=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1336=== RUN TestIsValidUploadKey/build_log_question_mark1337=== PAUSE TestIsValidUploadKey/build_log_question_mark1338=== RUN TestIsValidUploadKey/build_log_equals1339=== PAUSE TestIsValidUploadKey/build_log_equals1340=== RUN TestIsValidUploadKey/realisation1341=== PAUSE TestIsValidUploadKey/realisation1342=== RUN TestIsValidUploadKey/realisation_plus_in_output1343=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1344=== RUN TestIsValidUploadKey/nix-cache-info1345=== PAUSE TestIsValidUploadKey/nix-cache-info1346=== RUN TestIsValidUploadKey/index.html1347=== PAUSE TestIsValidUploadKey/index.html1348=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1349=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1350=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1351=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1352=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1353=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1354=== RUN TestIsValidUploadKey/traversal1355=== PAUSE TestIsValidUploadKey/traversal1356=== RUN TestIsValidUploadKey/traversal_nar1357=== PAUSE TestIsValidUploadKey/traversal_nar1358=== RUN TestIsValidUploadKey/absolute1359=== PAUSE TestIsValidUploadKey/absolute1360=== RUN TestIsValidUploadKey/empty_key1361=== PAUSE TestIsValidUploadKey/empty_key1362=== RUN TestIsValidUploadKey/unknown_type1363=== PAUSE TestIsValidUploadKey/unknown_type1364=== CONT TestProxyWriteTimeout/narinfo1365=== CONT TestProxyWriteTimeout/10_GiB_nar1366=== CONT TestProxyWriteTimeout/unknown_size1367=== CONT TestProxyWriteTimeout/1_GiB_nar1368=== CONT TestPush_RejectsBadRequests/no_roots1369--- PASS: TestProxyWriteTimeout (0.01s)1370 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1371 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1372 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1373 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)13742026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes1375=== CONT TestPush_RejectsBadRequests/bad_root13762026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes1377=== CONT TestPush_RejectsBadRequests/root_not_in_objects13782026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes1379=== CONT TestPush_RejectsBadRequests/no_objects13802026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes1381=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1382--- PASS: TestPush_RejectsBadRequests (0.46s)1383 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1384 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1385 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1386 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)13872026/10/05 11:22:55 INFO All 1 paths already cached1388=== NAME TestClientIntegration1389 client_integration_test.go:312: Retrieved narinfo from S3:1390 StorePath: /build/TestClientIntegration4237300401/002/store/hirxkj033sqy5nhyhf3qkja2n2yrxlsd-test-file.txt1391 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1392 Compression: zstd1393 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11394 NarSize: 1521395 References: 1396 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11397 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1398 client_integration_test.go:313: Decompressed .ls content (64 bytes):1399 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1400 client_integration_test.go:316: Testing garbage collection...14012026/10/05 11:22:55 INFO lead: acquired remote=192.0.2.1:12341402=== NAME TestClientCADerivations1403 client_ca_test.go:139: Found 1 dependencies (including self)1404--- PASS: TestGCBugBareHashReferences (0.65s)1405=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check14062026/10/05 11:22:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14072026/10/05 11:22:55 WARN mTLS auth: bound subjects configured but subject DN unavailable14082026/10/05 11:22:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1409--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.33s)1410=== CONT TestServerTLSConfig/no_client_CA1411=== CONT TestServerTLSConfig/not_a_PEM_file1412=== CONT TestServerTLSConfig/missing_CA_file1413--- PASS: TestServerTLSConfig (0.00s)1414 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1415 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1416 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1417=== CONT TestIsValidCachePath/narinfo1418=== CONT TestIsValidCachePath/index.html1419=== CONT TestIsValidCachePath/short_hash1420=== CONT TestIsValidCachePath/wrong_extension1421=== CONT TestIsValidCachePath/leading_slash1422=== CONT TestIsValidCachePath/empty1423=== CONT TestIsValidCachePath/random_path1424=== CONT TestIsValidCachePath/invalid_char_u1425=== CONT TestIsValidCachePath/invalid_char_e1426=== CONT TestIsValidCachePath/traversal_in_middle1427=== CONT TestIsValidCachePath/traversal_parent1428=== CONT TestIsValidCachePath/nar_uncompressed1429=== CONT TestIsValidCachePath/realisation1430=== CONT TestIsValidCachePath/log1431=== CONT TestIsValidCachePath/nix-cache-info1432=== CONT TestIsValidCachePath/ls1433=== CONT TestIsValidCachePath/nar_xz1434=== CONT TestIsValidCachePath/nar_bz21435=== CONT TestIsValidCachePath/nar_zst1436=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1437=== CONT TestParseSingleRange/none1438=== CONT TestParseSingleRange/open-ended1439=== CONT TestParseSingleRange/start_far_past_EOF1440=== CONT TestParseSingleRange/start_past_EOF1441=== CONT TestParseSingleRange/single_byte1442=== CONT TestParseSingleRange/suffix_exceeds_size1443--- PASS: TestIsValidCachePath (0.00s)1444 --- PASS: TestIsValidCachePath/narinfo (0.00s)1445 --- PASS: TestIsValidCachePath/index.html (0.00s)1446 --- PASS: TestIsValidCachePath/short_hash (0.00s)1447 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1448 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1449 --- PASS: TestIsValidCachePath/empty (0.00s)1450 --- PASS: TestIsValidCachePath/random_path (0.00s)1451 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1452 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1453 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1454 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1455 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1456 --- PASS: TestIsValidCachePath/realisation (0.00s)1457 --- PASS: TestIsValidCachePath/log (0.00s)1458 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1459 --- PASS: TestIsValidCachePath/ls (0.00s)1460 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1461 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1462 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1463 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1464=== CONT TestParseSingleRange/suffix1465=== CONT TestParseSingleRange/end_clamped_to_size1466=== CONT TestParseSingleRange/malformed_both_empty1467=== CONT TestParseSingleRange/closed1468=== CONT TestParseSingleRange/malformed_end_before_start1469=== CONT TestParseSingleRange/multi-range_ignored1470=== CONT TestParseSingleRange/malformed_no_dash1471=== CONT TestParseSingleRange/unknown_unit1472=== CONT TestGCEndsOnShutdown/before_the_run1473--- PASS: TestParseSingleRange (0.00s)1474 --- PASS: TestParseSingleRange/none (0.00s)1475 --- PASS: TestParseSingleRange/open-ended (0.00s)1476 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1477 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1478 --- PASS: TestParseSingleRange/single_byte (0.00s)1479 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1480 --- PASS: TestParseSingleRange/suffix (0.00s)1481 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1482 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1483 --- PASS: TestParseSingleRange/closed (0.00s)1484 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1485 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1486 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1487 --- PASS: TestParseSingleRange/unknown_unit (0.00s)14882026/10/05 11:22:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures14892026/10/05 11:22:55 INFO Garbage collection started14902026/10/05 11:22:55 INFO Aborted multipart uploads count=0 kept=014912026/10/05 11:22:55 WARN Force mode enabled - objects will be deleted immediately without grace period14922026/10/05 11:22:55 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=014932026/10/05 11:22:55 INFO Vacuumed table table=pending_closures1494=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1495=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1496=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1497=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1498=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1499=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1500=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1501=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1502=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15032026/10/05 11:22:55 INFO Vacuumed table table=pending_objects15042026/10/05 11:22:55 INFO Vacuumed table table=multipart_uploads15052026/10/05 11:22:55 INFO Vacuumed table table=closures15062026/10/05 11:22:55 INFO Vacuumed table table=objects1507--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)1508=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15092026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes15102026/10/05 11:22:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15112026/10/05 11:22:55 INFO Uploading ribim32y6516ngkfsbnk00x33pfv37j6-ca-test (144B)15122026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15132026/10/05 11:22:55 WARN Failed to register uploaded object key=ribim32y6516ngkfsbnk00x33pfv37j6.ls error="server returned 404: 404 page not found\n"15142026/10/05 11:22:55 WARN Failed to register uploaded object key=log/qmcifxd9x1361b3a9zjx89lhk4zl8nnj-ca-test.drv error="server returned 404: 404 page not found\n"15152026/10/05 11:22:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15162026/10/05 11:22:55 INFO Signed narinfos id=1 count=115172026/10/05 11:22:55 INFO Uploading 1 narinfos15182026/10/05 11:22:55 INFO Received complete push request method=POST path=/api/pushes/1/complete15192026/10/05 11:22:55 WARN Failed to register uploaded object key=ribim32y6516ngkfsbnk00x33pfv37j6.narinfo error="server returned 404: 404 page not found\n"1520=== NAME TestOrphanedObjectsGC1521 orphaned_objects_gc_test.go:290: GC Test Summary:1522 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1523 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1524 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1525 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1526 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1527--- PASS: TestOrphanedObjectsGC (0.75s)1528=== CONT TestClientErrorHandling/InvalidStorePath15292026/10/05 11:22:55 INFO Upload complete. (95ms)15302026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures1531=== NAME TestClientCADerivations1532 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2941216553/001/store/ribim32y6516ngkfsbnk00x33pfv37j6-ca-test1533 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1534 Compression: zstd1535 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1536 NarSize: 1441537 References: 1538 Deriver: /build/TestClientCADerivations2941216553/001/store/qmcifxd9x1361b3a9zjx89lhk4zl8nnj-ca-test.drv1539 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1540 client_ca_test.go:185: Checking for realisation files in S3...1541=== RUN TestService_RequireScope_OIDC/builder_may_write1542=== PAUSE TestService_RequireScope_OIDC/builder_may_write1543=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1544=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1545=== RUN TestService_RequireScope_OIDC/ops_may_admin1546=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1547=== RUN TestService_RequireScope_OIDC/ops_may_not_write1548=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1549=== RUN TestService_RequireScope_OIDC/reader_may_not_write1550=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1551=== NAME TestClientCADerivations1552 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1553 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1554=== RUN TestService_RequireScope_OIDC/static_token_may_admin1555=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1556=== RUN TestService_RequireScope_OIDC/static_token_may_write1557=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1558=== RUN TestService_RequireScope_OIDC/reader_may_read1559=== PAUSE TestService_RequireScope_OIDC/reader_may_read1560=== RUN TestService_RequireScope_OIDC/writer_implies_read1561=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1562=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1563=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1564=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1565=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1566=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1567=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1568=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1569=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1570=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1571=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1572=== CONT TestClientErrorHandling/ServerNotAvailable15732026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures15742026/10/05 11:22:55 INFO Received cleanup request method=DELETE path=/api/pending_closures1575--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.92s)1576=== CONT TestClientErrorHandling/InvalidAuthToken15772026/10/05 11:22:55 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/present15782026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures1579=== NAME TestClientCADerivations1580 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1581 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1582 error: binary cache 's3://bucket65?endpoint=http://localhost:37793®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2941216553/001/store'1583 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11584--- PASS: TestClientCADerivations (0.78s)1585=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15862026/10/05 11:22:55 INFO Received uploads request method=POST path=/1587=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15882026/10/05 11:22:55 INFO Received complete multipart upload request method=POST path=/1589=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15902026/10/05 11:22:55 INFO Received request for more parts method=POST path=/1591=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15922026/10/05 11:22:55 INFO Received uploads request method=POST path=/1593=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15942026/10/05 11:22:55 INFO Received uploads request method=POST path=/1595--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1596 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1597 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1598 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1599 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1600--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.30s)1601=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16022026/10/05 11:22:55 INFO Received request for more parts method=POST path=/16032026/10/05 11:22:55 INFO Received push request method=POST path=/api/pushes16042026/10/05 11:22:55 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16052026/10/05 11:22:55 INFO Uploading mmgd69a89kxbh27g6z5mn7bac9zd14zr-a (216B)16062026/10/05 11:22:55 INFO Uploading fvlk31j615n872nyhq33fkg81lik1dgd-shared-dep (136B)16072026/10/05 11:22:55 WARN Failed to register uploaded object key=mmgd69a89kxbh27g6z5mn7bac9zd14zr.ls error="server returned 404: 404 page not found\n"16082026/10/05 11:22:55 WARN Failed to register uploaded object key=hq2368as5z4c3yx0xx9mym57i3iswf40.ls error="server returned 404: 404 page not found\n"16092026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/1n33256y82x5gaqw708nbdnz1g3jwgxsw97xmdhr6isbfq76w4kk.nar.zst error="server returned 404: 404 page not found\n"16102026/10/05 11:22:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16112026/10/05 11:22:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16122026/10/05 11:22:55 WARN Failed to register uploaded object key=fvlk31j615n872nyhq33fkg81lik1dgd.ls error="server returned 404: 404 page not found\n"16132026/10/05 11:22:55 INFO Signed narinfos id=1 count=316142026/10/05 11:22:55 INFO Uploading 3 narinfos16152026/10/05 11:22:55 WARN Failed to register uploaded object key=fvlk31j615n872nyhq33fkg81lik1dgd.narinfo error="server returned 404: 404 page not found\n"16162026/10/05 11:22:55 WARN Failed to register uploaded object key=mmgd69a89kxbh27g6z5mn7bac9zd14zr.narinfo error="server returned 404: 404 page not found\n"16172026/10/05 11:22:55 INFO Received complete push request method=POST path=/api/pushes/1/complete16182026/10/05 11:22:55 WARN Failed to register uploaded object key=hq2368as5z4c3yx0xx9mym57i3iswf40.narinfo error="server returned 404: 404 page not found\n"1619=== NAME TestPinProtectsFromGC1620 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4171046357/001/store/cd3iishmqyicpfmric96nbsjqa3isjjd-pinned-file.txt1621 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4171046357/001/store/cf5vcynka4xzd40n0azz3xmfkhhfjgay-unpinned-file.txt16222026/10/05 11:22:55 INFO Upload complete. (63ms)1623=== NAME TestClientPushesUseOnePush1624 client_pushes_test.go:97: Retrieved narinfo from S3:1625 StorePath: /build/TestClientPushesUseOnePush1431518047/001/store/fvlk31j615n872nyhq33fkg81lik1dgd-shared-dep1626 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1627 Compression: zstd1628 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821629 NarSize: 1361630 References: 1631 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1632 client_pushes_test.go:97: Retrieved narinfo from S3:1633 StorePath: /build/TestClientPushesUseOnePush1431518047/001/store/mmgd69a89kxbh27g6z5mn7bac9zd14zr-a1634 URL: nar/1n33256y82x5gaqw708nbdnz1g3jwgxsw97xmdhr6isbfq76w4kk.nar.zst1635 Compression: zstd1636 NarHash: sha256:1n33256y82x5gaqw708nbdnz1g3jwgxsw97xmdhr6isbfq76w4kk1637 NarSize: 2161638 References: /build/TestClientPushesUseOnePush1431518047/001/store/fvlk31j615n872nyhq33fkg81lik1dgd-shared-dep1639 CA: text:sha256:14k0k0705jq1330y9syzr9s6vsbp8083c1mwdj66pcm3z0k3n3dv1640 client_pushes_test.go:97: Retrieved narinfo from S3:1641 StorePath: /build/TestClientPushesUseOnePush1431518047/001/store/hq2368as5z4c3yx0xx9mym57i3iswf40-b1642 URL: nar/1n33256y82x5gaqw708nbdnz1g3jwgxsw97xmdhr6isbfq76w4kk.nar.zst1643 Compression: zstd1644 NarHash: sha256:1n33256y82x5gaqw708nbdnz1g3jwgxsw97xmdhr6isbfq76w4kk1645 NarSize: 2161646 References: /build/TestClientPushesUseOnePush1431518047/001/store/fvlk31j615n872nyhq33fkg81lik1dgd-shared-dep1647 CA: text:sha256:14k0k0705jq1330y9syzr9s6vsbp8083c1mwdj66pcm3z0k3n3dv1648--- PASS: TestObjectStatsTrigger (0.29s)1649=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16502026/10/05 11:22:55 INFO Received complete multipart upload request method=POST path=/1651--- PASS: TestClientPushesUseOnePush (0.55s)1652=== CONT TestCacheConfigHandler/full_config,_no_issuer1653=== CONT TestCacheConfigHandler/no_signing_keys1654=== CONT TestCacheConfigHandler/no_cache_url_configured1655=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1656--- PASS: TestCacheConfigHandler (0.00s)1657 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1658 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1659 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1660 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1661=== CONT TestResolveDBConnectionString/flag_wins1662=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1663=== CONT TestResolveDBConnectionString/nothing_configured1664=== CONT TestResolveDBConnectionString/missing_file_is_an_error1665=== CONT TestResolveDBConnectionString/file_when_flag_empty1666=== CONT TestPendingClosureWriteTimeout/empty1667=== CONT TestPendingClosureWriteTimeout/670k_objects1668=== CONT TestPendingClosureWriteTimeout/400_objects1669=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1670--- PASS: TestResolveDBConnectionString (0.00s)1671 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1672 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1673 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1674 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1675 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16762026/10/05 11:22:55 INFO Received uploads request method=POST path=/api/pending_closures16772026/10/05 11:22:56 INFO Aborted multipart uploads count=0 kept=016782026/10/05 11:22:56 WARN Force mode enabled - objects will be deleted immediately without grace period16792026/10/05 11:22:56 INFO Received uploads request method=POST path=/api/pending_closures16802026/10/05 11:22:56 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=01681=== CONT TestIsValidUploadKey/narinfo1682=== CONT TestIsValidUploadKey/absolute1683=== CONT TestIsValidUploadKey/traversal_nar16842026/10/05 11:22:56 INFO Vacuumed table table=pending_closures1685=== CONT TestIsValidUploadKey/empty_key1686=== CONT TestIsValidUploadKey/traversal1687=== CONT TestIsValidUploadKey/build_log_question_mark1688=== CONT TestIsValidUploadKey/build_log_plus_in_name1689=== CONT TestIsValidUploadKey/build_log_home-manager_file1690=== CONT TestIsValidUploadKey/build_log1691=== CONT TestIsValidUploadKey/listing1692=== CONT TestIsValidUploadKey/nar_plain1693=== CONT TestIsValidUploadKey/nar_xz1694=== CONT TestIsValidUploadKey/nar_zst1695=== CONT TestIsValidUploadKey/index.html1696=== CONT TestIsValidUploadKey/build_log_equals1697=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1698=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1699=== CONT TestIsValidUploadKey/nix-cache-info1700=== CONT TestIsValidUploadKey/narinfo_key,_nar_type17012026/10/05 11:22:56 INFO Vacuumed table table=pending_objects1702=== CONT TestIsValidUploadKey/realisation_plus_in_output1703=== CONT TestIsValidUploadKey/unknown_type1704=== CONT TestIsValidUploadKey/realisation1705--- PASS: TestIsValidUploadKey (0.00s)1706 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1707 --- PASS: TestIsValidUploadKey/absolute (0.00s)1708 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1709 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1710 --- PASS: TestIsValidUploadKey/traversal (0.00s)1711 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1712 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1713 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1714 --- PASS: TestIsValidUploadKey/build_log (0.00s)1715 --- PASS: TestIsValidUploadKey/listing (0.00s)1716 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1717 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1718 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1719 --- PASS: TestIsValidUploadKey/index.html (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1721 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1722 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1723 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1724 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1725 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1726 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1727 --- PASS: TestIsValidUploadKey/realisation (0.00s)1728=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17292026/10/05 11:22:56 INFO Vacuumed table table=multipart_uploads17302026/10/05 11:22:56 INFO Vacuumed table table=closures17312026/10/05 11:22:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.808413ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17322026/10/05 11:22:56 INFO Vacuumed table table=objects1733=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17342026/10/05 11:22:56 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]1735=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17362026/10/05 11:22:56 INFO Aborted multipart uploads count=0 kept=017372026/10/05 11:22:56 WARN Authentication failed token_preview=eyJhbGciOi...sLX0aam17w token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1738=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1739=== CONT TestService_RequireScope_OIDC/builder_may_write1740--- PASS: TestService_AuthMiddleware_OIDC (0.43s)1741 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1742 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1743 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1744 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)17452026/10/05 11:22:56 WARN Force mode enabled - objects will be deleted immediately without grace period1746=== CONT TestService_RequireScope_OIDC/reader_may_read1747=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1748=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1749=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1750=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1751=== CONT TestService_RequireScope_OIDC/writer_implies_read1752=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17532026/10/05 11:22:56 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]1754=== CONT TestService_RequireScope_OIDC/reader_may_not_write1755=== CONT TestService_RequireScope_OIDC/static_token_may_write1756=== CONT TestService_RequireScope_OIDC/ops_may_admin1757=== CONT TestService_RequireScope_OIDC/static_token_may_admin1758=== CONT TestService_RequireScope_OIDC/ops_may_not_write1759=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1760--- PASS: TestService_RequireScope_OIDC (0.47s)1761 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1762 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1763 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1764 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1765 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1766 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1767 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1768 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1769 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1770 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1771 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1772 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1773 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1774 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)17752026/10/05 11:22:56 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=017762026/10/05 11:22:56 INFO Vacuumed table table=pending_closures17772026/10/05 11:22:56 INFO Vacuumed table table=pending_objects17782026/10/05 11:22:56 INFO Vacuumed table table=multipart_uploads17792026/10/05 11:22:56 INFO Vacuumed table table=closures17802026/10/05 11:22:56 INFO Vacuumed table table=objects17812026/10/05 11:22:56 INFO Received push request method=POST path=/api/pushes17822026/10/05 11:22:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17832026/10/05 11:22:56 INFO Uploading cd3iishmqyicpfmric96nbsjqa3isjjd-pinned-file.txt (128B)1784--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1785 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.34s)1786 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.32s)17872026/10/05 11:22:56 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17882026/10/05 11:22:56 WARN Failed to register uploaded object key=cd3iishmqyicpfmric96nbsjqa3isjjd.ls error="server returned 404: 404 page not found\n"17892026/10/05 11:22:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17902026/10/05 11:22:56 INFO Signed narinfos id=1 count=117912026/10/05 11:22:56 INFO Uploading 1 narinfos17922026/10/05 11:22:56 INFO Received complete push request method=POST path=/api/pushes/1/complete17932026/10/05 11:22:56 WARN Failed to register uploaded object key=cd3iishmqyicpfmric96nbsjqa3isjjd.narinfo error="server returned 404: 404 page not found\n"17942026/10/05 11:22:56 INFO Upload complete. (59ms)17952026/10/05 11:22:56 INFO Aborted multipart uploads count=0 kept=017962026/10/05 11:22:56 WARN Force mode enabled - objects will be deleted immediately without grace period17972026-10-05 11:22:56.074 UTC [1644] ERROR: canceling statement due to user request17982026-10-05 11:22:56.074 UTC [1644] CONTEXT: PL/pgSQL expression "0"1799 PL/pgSQL function object_stats_apply() line 3 during statement block local variable initialization18002026-10-05 11:22:56.074 UTC [1644] STATEMENT: -- name: MarkStaleObjects :execrows1801 WITH RECURSIVE ct AS (1802 SELECT timezone('UTC', now()) AS now1803 ),1804 closure_reach AS (1805 -- Start with all closure keys1806 SELECT o.key, o.refs1807 FROM objects o1808 INNER JOIN closures c ON o.key = c.key1809 UNION1810 -- Recursively add all referenced objects1811 SELECT o.key, o.refs1812 FROM objects o1813 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1814 ),1815 reachable_objects AS (1816 SELECT DISTINCT key FROM closure_reach1817 ),1818 stale_objects AS (1819 SELECT o.key1820 FROM objects AS o, ct1821 WHERE1822 NOT EXISTS (1823 SELECT 11824 FROM reachable_objects ro1825 WHERE ro.key = o.key1826 )1827 AND NOT EXISTS (1828 SELECT 11829 FROM pending_objects AS po1830 WHERE po.key = o.key1831 )1832 AND o.deleted_at IS NULL -- Only mark fresh objects1833 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1834 FOR UPDATE1835 )1836 UPDATE objects1837 SET1838 deleted_at = ct.now,1839 first_deleted_at = COALESCE(first_deleted_at, ct.now)1840 FROM stale_objects, ct1841 WHERE objects.key = stale_objects.key1842 18432026/10/05 11:22:56 INFO Aborted multipart uploads count=0 kept=018442026/10/05 11:22:56 WARN Force mode enabled - objects will be deleted immediately without grace period18452026/10/05 11:22:56 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37793/bucket88/?delete=\": context canceled"1846--- PASS: TestGCEndsOnShutdown (0.00s)1847 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)1848 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.29s)1849 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.28s)18502026/10/05 11:22:56 INFO Received uploads request method=POST path=/api/pending_closures18512026/10/05 11:22:56 INFO Received push request method=POST path=/api/pushes18522026/10/05 11:22:56 INFO Received uploads request method=POST path=/api/pending_closures18532026/10/05 11:22:56 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18542026/10/05 11:22:56 INFO Uploading 8mp8ww3pkgxb3afiphrpi32kqvlp67dl-top (224B)18552026/10/05 11:22:56 INFO Uploading hmlx5s1r0khx4b4pck2xkl9rbchqijlm-shared-dep (136B)18562026/10/05 11:22:56 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18572026/10/05 11:22:56 INFO Uploading rqxiwqgzqyqwaxqpvmv4xqjk1nrqynkl-shared-dep (136B)18582026/10/05 11:22:56 INFO Uploading j6qkfggnsjpl31b5ycvw26rh5yfmfrai-b (216B)18592026/10/05 11:22:56 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18602026/10/05 11:22:56 WARN Failed to register uploaded object key=nar/146shjxpjmkd6s1j5fjcpkvcxbx9hvmq16z19rcp5xa8ly0x1iak.nar.zst error="server returned 404: 404 page not found\n"18612026/10/05 11:22:56 WARN Failed to register uploaded object key=8mp8ww3pkgxb3afiphrpi32kqvlp67dl.ls error="server returned 404: 404 page not found\n"18622026/10/05 11:22:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18632026/10/05 11:22:56 WARN Failed to register uploaded object key=gc0vygn9x6y5v5s9zqmacwfccrdx9nx7.ls error="server returned 404: 404 page not found\n"18642026/10/05 11:22:56 WARN Failed to register uploaded object key=hmlx5s1r0khx4b4pck2xkl9rbchqijlm.ls error="server returned 404: 404 page not found\n"18652026/10/05 11:22:56 WARN Failed to register uploaded object key=nar/06b26hwzk53v727yyk8hargzz0y6qgihvzpjwwp1pxdszhb1qmh3.nar.zst error="server returned 404: 404 page not found\n"18662026/10/05 11:22:56 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18672026/10/05 11:22:56 INFO Signed narinfos id=1 count=218682026/10/05 11:22:56 WARN Failed to register uploaded object key=j6qkfggnsjpl31b5ycvw26rh5yfmfrai.ls error="server returned 404: 404 page not found\n"18692026/10/05 11:22:56 INFO Uploading 2 narinfos18702026/10/05 11:22:56 WARN Failed to register uploaded object key=rqxiwqgzqyqwaxqpvmv4xqjk1nrqynkl.ls error="server returned 404: 404 page not found\n"18712026/10/05 11:22:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18722026/10/05 11:22:56 INFO Signed narinfos id=1 count=218732026/10/05 11:22:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18742026/10/05 11:22:56 INFO Signed narinfos id=2 count=218752026/10/05 11:22:56 INFO Uploading 4 narinfos18762026/10/05 11:22:56 WARN Failed to register uploaded object key=8mp8ww3pkgxb3afiphrpi32kqvlp67dl.narinfo error="server returned 404: 404 page not found\n"18772026/10/05 11:22:56 INFO Received complete push request method=POST path=/api/pushes/1/complete18782026/10/05 11:22:56 WARN Failed to register uploaded object key=hmlx5s1r0khx4b4pck2xkl9rbchqijlm.narinfo error="server returned 404: 404 page not found\n"18792026/10/05 11:22:56 WARN Failed to register uploaded object key=rqxiwqgzqyqwaxqpvmv4xqjk1nrqynkl.narinfo error="server returned 404: 404 page not found\n"18802026/10/05 11:22:56 WARN Failed to register uploaded object key=gc0vygn9x6y5v5s9zqmacwfccrdx9nx7.narinfo error="server returned 404: 404 page not found\n"18812026/10/05 11:22:56 WARN Failed to register uploaded object key=j6qkfggnsjpl31b5ycvw26rh5yfmfrai.narinfo error="server returned 404: 404 page not found\n"18822026/10/05 11:22:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18832026/10/05 11:22:56 WARN Failed to register uploaded object key=rqxiwqgzqyqwaxqpvmv4xqjk1nrqynkl.narinfo error="server returned 404: 404 page not found\n"18842026/10/05 11:22:56 INFO Upload complete. (53ms)1885=== NAME TestClientSharedPathCommittedMidPush1886 client_integration_test.go:680: Retrieved narinfo from S3:1887 StorePath: /build/TestClientSharedPathCommittedMidPush411749651/001/store/hmlx5s1r0khx4b4pck2xkl9rbchqijlm-shared-dep1888 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1889 Compression: zstd1890 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821891 NarSize: 1361892 References: 1893 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18942026/10/05 11:22:56 INFO Completed upload id=118952026/10/05 11:22:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1896 client_integration_test.go:680: Retrieved narinfo from S3:1897 StorePath: /build/TestClientSharedPathCommittedMidPush411749651/001/store/8mp8ww3pkgxb3afiphrpi32kqvlp67dl-top1898 URL: nar/146shjxpjmkd6s1j5fjcpkvcxbx9hvmq16z19rcp5xa8ly0x1iak.nar.zst1899 Compression: zstd1900 NarHash: sha256:146shjxpjmkd6s1j5fjcpkvcxbx9hvmq16z19rcp5xa8ly0x1iak1901 NarSize: 2241902 References: /build/TestClientSharedPathCommittedMidPush411749651/001/store/hmlx5s1r0khx4b4pck2xkl9rbchqijlm-shared-dep1903 CA: text:sha256:0k5vys1yj7rxm5fnmcycqs7gvf6nj3nd83bg09m4k49xxpbj84ci19042026/10/05 11:22:56 INFO Completed upload id=219052026/10/05 11:22:56 INFO Upload complete. (65ms)1906=== NAME TestClientFallsBackToClosures1907 client_pushes_test.go:112: Retrieved narinfo from S3:1908 StorePath: /build/TestClientFallsBackToClosures1327336095/001/store/rqxiwqgzqyqwaxqpvmv4xqjk1nrqynkl-shared-dep1909 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1910 Compression: zstd1911 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821912 NarSize: 1361913 References: 1914 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19152026/10/05 11:22:56 INFO Received uploads request method=POST path=/api/pending_closures1916--- PASS: TestClientSharedPathCommittedMidPush (0.44s)1917=== NAME TestClientFallsBackToClosures1918 client_pushes_test.go:112: Retrieved narinfo from S3:1919 StorePath: /build/TestClientFallsBackToClosures1327336095/001/store/gc0vygn9x6y5v5s9zqmacwfccrdx9nx7-a1920 URL: nar/06b26hwzk53v727yyk8hargzz0y6qgihvzpjwwp1pxdszhb1qmh3.nar.zst1921 Compression: zstd1922 NarHash: sha256:06b26hwzk53v727yyk8hargzz0y6qgihvzpjwwp1pxdszhb1qmh31923 NarSize: 2161924 References: /build/TestClientFallsBackToClosures1327336095/001/store/rqxiwqgzqyqwaxqpvmv4xqjk1nrqynkl-shared-dep1925 CA: text:sha256:0i3fcs6b7p9pvpjj08ppgsn319x9v36gwb24snks98as5gfvsq8d19262026/10/05 11:22:56 INFO Received push request method=POST path=/api/pushes1927 client_pushes_test.go:112: Retrieved narinfo from S3:1928 StorePath: /build/TestClientFallsBackToClosures1327336095/001/store/j6qkfggnsjpl31b5ycvw26rh5yfmfrai-b1929 URL: nar/06b26hwzk53v727yyk8hargzz0y6qgihvzpjwwp1pxdszhb1qmh3.nar.zst1930 Compression: zstd1931 NarHash: sha256:06b26hwzk53v727yyk8hargzz0y6qgihvzpjwwp1pxdszhb1qmh31932 NarSize: 2161933 References: /build/TestClientFallsBackToClosures1327336095/001/store/rqxiwqgzqyqwaxqpvmv4xqjk1nrqynkl-shared-dep1934 CA: text:sha256:0i3fcs6b7p9pvpjj08ppgsn319x9v36gwb24snks98as5gfvsq8d19352026/10/05 11:22:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19362026/10/05 11:22:56 INFO Uploading cf5vcynka4xzd40n0azz3xmfkhhfjgay-unpinned-file.txt (128B)1937--- PASS: TestClientFallsBackToClosures (0.48s)19382026/10/05 11:22:56 WARN Failed to register uploaded object key=cf5vcynka4xzd40n0azz3xmfkhhfjgay.ls error="server returned 404: 404 page not found\n"19392026/10/05 11:22:56 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19402026/10/05 11:22:56 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19412026/10/05 11:22:56 INFO Signed narinfos id=2 count=119422026/10/05 11:22:56 INFO Uploading 1 narinfos19432026/10/05 11:22:56 INFO Received complete push request method=POST path=/api/pushes/2/complete19442026/10/05 11:22:56 WARN Failed to register uploaded object key=cf5vcynka4xzd40n0azz3xmfkhhfjgay.narinfo error="server returned 404: 404 page not found\n"19452026/10/05 11:22:56 INFO Upload complete. (40ms)19462026/10/05 11:22:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures19472026/10/05 11:22:56 INFO Garbage collection started19482026/10/05 11:22:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19492026/10/05 11:22:56 INFO Aborted multipart uploads count=0 kept=019502026/10/05 11:22:56 WARN Force mode enabled - objects will be deleted immediately without grace period19512026/10/05 11:22:56 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=019522026/10/05 11:22:56 INFO Vacuumed table table=pending_closures19532026/10/05 11:22:56 INFO Vacuumed table table=pending_objects19542026/10/05 11:22:56 INFO Vacuumed table table=multipart_uploads19552026/10/05 11:22:56 INFO Vacuumed table table=closures19562026/10/05 11:22:56 INFO Vacuumed table table=objects19572026/10/05 11:22:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19582026/10/05 11:22:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.148172ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1959--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.63s)1960=== NAME TestOrphanedObjectsGCStressTest1961 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19622026/10/05 11:22:56 INFO lead: released remote=192.0.2.1:12341963--- PASS: TestLeadEndsOnShutdown (1.49s)1964=== NAME TestOrphanedObjectsGCStressTest1965 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19662026/10/05 11:22:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=870.378683ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1967 orphaned_objects_gc_test.go:509: Stress test completed successfully:1968 orphaned_objects_gc_test.go:510: - Active objects preserved: 201969 orphaned_objects_gc_test.go:511: - Objects deleted: 2101970 orphaned_objects_gc_test.go:512: - Total GC'd: 2101971--- PASS: TestOrphanedObjectsGCStressTest (1.83s)1972--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)1973 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1974 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1975 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.95s)19762026/10/05 11:22:56 INFO lead: released remote=192.0.2.1:12341977--- PASS: TestPendingClosureWriteTimeout (0.00s)1978 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1979 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1980 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1981 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (0.94s)19822026/10/05 11:22:56 INFO lead: acquired remote=192.0.2.1:123419832026/10/05 11:22:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.650635187s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19842026/10/05 11:22:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01985=== NAME TestClientIntegration1986 client_integration_test.go:323: Objects in database after GC:1987 client_integration_test.go:323: Successfully deleted all objects with GC --force1988--- PASS: TestClientIntegration (2.65s)19892026/10/05 11:22:58 INFO lead: released remote=192.0.2.1:12341990--- PASS: TestLeadElectsOneAndHandsOver (2.70s)19912026/10/05 11:22:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019922026/10/05 11:22:58 INFO Received create pin request method=POST path=/api/pins/myapp19932026/10/05 11:22:58 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4171046357/001/store/cd3iishmqyicpfmric96nbsjqa3isjjd-pinned-file.txt narinfo_key=cd3iishmqyicpfmric96nbsjqa3isjjd.narinfo19942026/10/05 11:22:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures19952026/10/05 11:22:58 INFO Garbage collection started19962026/10/05 11:22:58 INFO Aborted multipart uploads count=0 kept=019972026/10/05 11:22:58 WARN Force mode enabled - objects will be deleted immediately without grace period19982026/10/05 11:22:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019992026/10/05 11:22:58 INFO Vacuumed table table=pending_closures20002026/10/05 11:22:58 INFO Vacuumed table table=pending_objects20012026/10/05 11:22:58 INFO Vacuumed table table=multipart_uploads20022026/10/05 11:22:58 INFO Vacuumed table table=closures20032026/10/05 11:22:58 INFO Vacuumed table table=objects20042026/10/05 11:22:58 WARN Rate limiter enabled after throttle name=s3-test rate=520052026/10/05 11:22:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2006=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2007 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102008 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002009--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.84s)2010--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.67s)20112026/10/05 11:22:59 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-config20122026/10/05 11:22:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.399931ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20132026/10/05 11:22:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.698745ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20142026/10/05 11:22:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=781.658092ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2015=== NAME TestPinProtectsFromGC2016 client_integration_test.go:840: Pin successfully protected closure from garbage collection2017--- PASS: TestPinProtectsFromGC (4.52s)2018--- PASS: TestConnectWaitsForAPeerMigration (5.11s)20192026/10/05 11:23:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.557522765s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20202026/10/05 11:23:01 INFO Aborted multipart uploads count=1 kept=020212026/10/05 11:23:01 INFO Received cleanup request method=DELETE path=/api/pending_closures20222026/10/05 11:23:01 INFO Aborted multipart uploads count=1 kept=02023--- PASS: TestPendingCleanupUsesOneCutoff (6.31s)20242026/10/05 11:23:02 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"20252026/10/05 11:23:02 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-config20262026/10/05 11:23:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.507459ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/05 11:23:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.203802ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/05 11:23:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=817.434024ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/05 11:23:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.659819958s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20302026/10/05 11:23:05 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_closures20312026/10/05 11:23:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.033777ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20322026/10/05 11:23:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.001062ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20332026/10/05 11:23:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=780.144372ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20342026/10/05 11:23:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.715384771s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2035--- PASS: TestClientErrorHandling (0.00s)2036 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2037 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.32s)2038 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.83s)2039PASS20402026-10-05 11:23:08.923 UTC [131] LOG: received smart shutdown request20412026-10-05 11:23:08.926 UTC [131] LOG: background worker "logical replication launcher" (PID 141) exited with exit code 120422026-10-05 11:23:08.937 UTC [136] LOG: shutting down20432026-10-05 11:23:08.938 UTC [136] LOG: checkpoint starting: shutdown immediate20442026-10-05 11:23:09.469 UTC [136] LOG: checkpoint complete: wrote 10984 buffers (67.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.184 s, sync=0.325 s, total=0.532 s; sync files=31000, longest=0.089 s, average=0.001 s; distance=428511 kB, estimate=428511 kB; lsn=0/1B9DDA20, redo lsn=0/1B9DDA2020452026-10-05 11:23:09.541 UTC [131] LOG: database system is shut down2046Running OIDC tests...2047=== RUN TestAudienceForIssuer2048=== PAUSE TestAudienceForIssuer2049=== RUN TestGlobMatch2050=== PAUSE TestGlobMatch2051=== RUN TestValidateToken_ValidToken2052=== PAUSE TestValidateToken_ValidToken2053=== RUN TestValidateToken_WrongAudience2054=== PAUSE TestValidateToken_WrongAudience2055=== RUN TestValidateToken_Expired2056=== PAUSE TestValidateToken_Expired2057=== RUN TestValidateToken_BoundClaimsMismatch2058=== PAUSE TestValidateToken_BoundClaimsMismatch2059=== RUN TestValidateToken_BoundSubjectMismatch2060=== PAUSE TestValidateToken_BoundSubjectMismatch2061=== RUN TestValidateToken_MultipleProviders2062=== PAUSE TestValidateToken_MultipleProviders2063=== RUN TestValidateToken_NoMatchingProvider2064=== PAUSE TestValidateToken_NoMatchingProvider2065=== RUN TestValidateToken_KubernetesServiceAccount2066=== PAUSE TestValidateToken_KubernetesServiceAccount2067=== RUN TestNewValidator_KubernetesRequiresCA2068=== PAUSE TestNewValidator_KubernetesRequiresCA2069=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2070=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2071=== RUN TestPins_ReservedForMatchingRule2072=== PAUSE TestPins_ReservedForMatchingRule2073=== RUN TestPins_TopLevelShorthand2074=== PAUSE TestPins_TopLevelShorthand2075=== RUN TestPins_ConfigValidation2076=== PAUSE TestPins_ConfigValidation2077=== RUN TestScopes_LegacyProviderDefaultsToWrite2078=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2079=== RUN TestScopes_Rules2080=== PAUSE TestScopes_Rules2081=== RUN TestScopes_ConfigValidation2082=== PAUSE TestScopes_ConfigValidation2083=== CONT TestAudienceForIssuer2084=== CONT TestValidateToken_BoundClaimsMismatch2085--- PASS: TestAudienceForIssuer (0.00s)2086=== CONT TestValidateToken_Expired2087=== CONT TestValidateToken_KubernetesServiceAccount2088=== CONT TestPins_ConfigValidation2089=== CONT TestPins_TopLevelShorthand2090=== CONT TestScopes_Rules2091=== CONT TestScopes_LegacyProviderDefaultsToWrite2092=== CONT TestValidateToken_MultipleProviders2093=== CONT TestValidateToken_NoMatchingProvider2094=== CONT TestValidateToken_BoundSubjectMismatch2095=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2096=== CONT TestPins_ReservedForMatchingRule2097=== CONT TestScopes_ConfigValidation2098=== CONT TestValidateToken_ValidToken2099=== CONT TestGlobMatch2100=== RUN TestGlobMatch/foo_foo2101=== PAUSE TestGlobMatch/foo_foo2102=== RUN TestGlobMatch/foo_bar2103=== PAUSE TestGlobMatch/foo_bar2104=== RUN TestGlobMatch/*_2105=== PAUSE TestGlobMatch/*_2106=== RUN TestGlobMatch/*_anything2107=== CONT TestNewValidator_KubernetesRequiresCA2108=== PAUSE TestGlobMatch/*_anything2109=== RUN TestGlobMatch/foo*_foo2110=== PAUSE TestGlobMatch/foo*_foo2111=== RUN TestGlobMatch/foo*_foobar2112=== CONT TestValidateToken_WrongAudience2113=== PAUSE TestGlobMatch/foo*_foobar2114--- PASS: TestPins_ConfigValidation (0.00s)2115--- PASS: TestScopes_ConfigValidation (0.00s)2116=== RUN TestGlobMatch/foo*_bar2117=== PAUSE TestGlobMatch/foo*_bar2118=== RUN TestGlobMatch/*bar_bar2119=== PAUSE TestGlobMatch/*bar_bar2120=== RUN TestGlobMatch/*bar_foobar2121=== PAUSE TestGlobMatch/*bar_foobar2122=== RUN TestGlobMatch/*bar_foo2123=== PAUSE TestGlobMatch/*bar_foo2124=== RUN TestGlobMatch/foo*bar_foobar2125=== PAUSE TestGlobMatch/foo*bar_foobar2126=== RUN TestGlobMatch/foo*bar_foo123bar2127=== PAUSE TestGlobMatch/foo*bar_foo123bar2128=== RUN TestGlobMatch/foo*bar_foobarbaz2129=== PAUSE TestGlobMatch/foo*bar_foobarbaz2130=== RUN TestGlobMatch/*/*_foo/bar2131=== PAUSE TestGlobMatch/*/*_foo/bar2132=== RUN TestGlobMatch/*/*_foo2133=== PAUSE TestGlobMatch/*/*_foo2134=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2135=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2136=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02137=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02138=== RUN TestGlobMatch/refs/*/main_refs/heads/main2139=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2140=== RUN TestGlobMatch/fo?_foo2141=== PAUSE TestGlobMatch/fo?_foo2142=== RUN TestGlobMatch/fo?_fo2143=== PAUSE TestGlobMatch/fo?_fo2144=== RUN TestGlobMatch/fo?_fooo2145=== PAUSE TestGlobMatch/fo?_fooo2146=== RUN TestGlobMatch/?oo_foo2147=== PAUSE TestGlobMatch/?oo_foo2148=== RUN TestGlobMatch/?oo_boo2149=== PAUSE TestGlobMatch/?oo_boo2150=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2151=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2152=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2153=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2154=== CONT TestGlobMatch/foo_foo2155=== CONT TestGlobMatch/?oo_boo2156=== CONT TestGlobMatch/foo*_foobar2157=== CONT TestGlobMatch/foo*bar_foobar2158=== CONT TestGlobMatch/*bar_foobar2159=== CONT TestGlobMatch/foo*_foo2160=== CONT TestGlobMatch/*_anything2161=== CONT TestGlobMatch/?oo_foo2162=== CONT TestGlobMatch/fo?_fooo2163=== CONT TestGlobMatch/fo?_fo2164=== CONT TestGlobMatch/fo?_foo2165=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2166=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02167=== CONT TestGlobMatch/*/*_foo/bar2168=== CONT TestGlobMatch/*/*_foo2169=== CONT TestGlobMatch/*_2170=== CONT TestGlobMatch/foo_bar2171=== CONT TestGlobMatch/foo*bar_foobarbaz2172=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2173=== CONT TestGlobMatch/*bar_foo2174=== CONT TestGlobMatch/foo*bar_foo123bar2175=== CONT TestGlobMatch/*bar_bar2176=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2177=== CONT TestGlobMatch/refs/*/main_refs/heads/main2178=== CONT TestGlobMatch/foo*_bar2179--- PASS: TestGlobMatch (0.00s)2180 --- PASS: TestGlobMatch/foo_foo (0.00s)2181 --- PASS: TestGlobMatch/?oo_boo (0.00s)2182 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2183 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2184 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2185 --- PASS: TestGlobMatch/foo*_foo (0.00s)2186 --- PASS: TestGlobMatch/*_anything (0.00s)2187 --- PASS: TestGlobMatch/?oo_foo (0.00s)2188 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2189 --- PASS: TestGlobMatch/fo?_fo (0.00s)2190 --- PASS: TestGlobMatch/fo?_foo (0.00s)2191 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2192 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2193 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2194 --- PASS: TestGlobMatch/*/*_foo (0.00s)2195 --- PASS: TestGlobMatch/*_ (0.00s)2196 --- PASS: TestGlobMatch/foo_bar (0.00s)2197 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2198 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2199 --- PASS: TestGlobMatch/*bar_foo (0.00s)2200 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2201 --- PASS: TestGlobMatch/*bar_bar (0.00s)2202 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2203 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2204 --- PASS: TestGlobMatch/foo*_bar (0.00s)22052026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36107/oidc2206--- PASS: TestPins_ReservedForMatchingRule (0.04s)22072026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34065/oidc2208--- PASS: TestValidateToken_ValidToken (0.05s)22092026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34267/oidc22102026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36773/oidc2211--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)2212--- PASS: TestScopes_Rules (0.07s)22132026/10/05 11:23:11 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232214--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)22152026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36965/oidc2216--- PASS: TestPins_TopLevelShorthand (0.14s)22172026/10/05 11:23:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4450322182026/10/05 11:23:11 http: TLS handshake error from 127.0.0.1:33590: remote error: tls: bad certificate2219--- PASS: TestNewValidator_KubernetesRequiresCA (0.14s)22202026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43027/oidc2221--- PASS: TestValidateToken_BoundClaimsMismatch (0.15s)2222--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)22232026/10/05 11:23:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33291/oidc22242026/10/05 11:23:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37539/oidc2225--- PASS: TestValidateToken_MultipleProviders (0.16s)22262026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44727/oidc2227--- PASS: TestValidateToken_WrongAudience (0.17s)22282026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46219/oidc2229--- PASS: TestValidateToken_Expired (0.23s)22302026/10/05 11:23:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41171/oidc2231--- PASS: TestValidateToken_NoMatchingProvider (0.35s)22322026/10/05 11:23:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36729/oidc2233--- PASS: TestValidateToken_BoundSubjectMismatch (0.41s)2234PASS2235Running hook tests...2236=== RUN TestSendPathsEmpty2237=== PAUSE TestSendPathsEmpty2238=== RUN TestQueueEnqueueAndFetch2239=== PAUSE TestQueueEnqueueAndFetch2240=== RUN TestQueueDeduplication2241=== PAUSE TestQueueDeduplication2242=== RUN TestQueueRemove2243=== PAUSE TestQueueRemove2244=== RUN TestQueueFetchBatchLimit2245=== PAUSE TestQueueFetchBatchLimit2246=== RUN TestQueueRetryMovesToBack2247=== PAUSE TestQueueRetryMovesToBack2248=== RUN TestQueueFetchRemoveLifecycle2249=== PAUSE TestQueueFetchRemoveLifecycle2250=== RUN TestQueueConcurrentWriters2251=== PAUSE TestQueueConcurrentWriters2252=== RUN TestQueueRemoveLargeClosure2253=== PAUSE TestQueueRemoveLargeClosure2254=== RUN TestServerClientIntegration2255=== PAUSE TestServerClientIntegration2256=== RUN TestServerQueueError2257=== PAUSE TestServerQueueError2258=== RUN TestGetListenerSocketActivation2259 server_test.go:210: === RUN TestGetListenerSocketActivation2260 --- PASS: TestGetListenerSocketActivation (0.00s)2261 PASS2262 2263--- PASS: TestGetListenerSocketActivation (0.01s)2264=== RUN TestDrainIsolatesPoisonPath2265=== PAUSE TestDrainIsolatesPoisonPath2266=== RUN TestRunNotBlockedByPoisonHead2267=== PAUSE TestRunNotBlockedByPoisonHead2268=== RUN TestDrainGivesUpWhenServerDown2269=== PAUSE TestDrainGivesUpWhenServerDown2270=== RUN TestFailedPathPrunedByLaterClosure2271=== PAUSE TestFailedPathPrunedByLaterClosure2272=== RUN TestWorkerUploadsAndRemoves2273=== PAUSE TestWorkerUploadsAndRemoves2274=== RUN TestWorkerSkipsGCdPaths2275=== PAUSE TestWorkerSkipsGCdPaths2276=== RUN TestWorkerPrunesClosureDeps2277=== PAUSE TestWorkerPrunesClosureDeps2278=== RUN TestDrainTimeout2279=== PAUSE TestDrainTimeout2280=== CONT TestSendPathsEmpty2281=== CONT TestDrainGivesUpWhenServerDown2282=== CONT TestWorkerSkipsGCdPaths2283=== CONT TestServerClientIntegration2284=== CONT TestQueueFetchRemoveLifecycle2285=== CONT TestQueueRetryMovesToBack2286=== CONT TestQueueFetchBatchLimit2287=== CONT TestQueueRemove2288=== CONT TestQueueConcurrentWriters2289=== CONT TestQueueDeduplication2290=== CONT TestRunNotBlockedByPoisonHead2291=== CONT TestQueueEnqueueAndFetch2292=== CONT TestDrainIsolatesPoisonPath2293=== CONT TestQueueRemoveLargeClosure2294=== CONT TestDrainTimeout2295=== CONT TestServerQueueError2296=== CONT TestWorkerUploadsAndRemoves2297=== CONT TestWorkerPrunesClosureDeps2298=== CONT TestFailedPathPrunedByLaterClosure2299--- PASS: TestSendPathsEmpty (0.00s)2300--- PASS: TestServerClientIntegration (0.00s)23012026/10/05 11:23:11 ERROR Failed to queue paths error="permission denied" count=12302--- PASS: TestServerQueueError (0.00s)23032026/10/05 11:23:11 INFO Uploading batch count=223042026/10/05 11:23:11 INFO Uploading batch count=423052026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=423062026/10/05 11:23:11 INFO Upload queue status pending=223072026/10/05 11:23:11 INFO Uploading batch count=123082026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=123092026/10/05 11:23:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1514837752/002/nonexistent23102026/10/05 11:23:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1607860190/002/bbb23112026/10/05 11:23:11 INFO Upload queue status pending=223122026/10/05 11:23:11 INFO Upload queue status pending=223132026/10/05 11:23:11 INFO Upload queue status pending=323142026/10/05 11:23:11 INFO Uploading batch count=123152026/10/05 11:23:11 INFO Uploading batch count=123162026/10/05 11:23:11 INFO Uploading batch count=123172026/10/05 11:23:11 INFO Uploading batch count=123182026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=123192026/10/05 11:23:11 INFO Uploading batch count=22320--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23212026/10/05 11:23:11 INFO Uploading batch count=223222026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=223232026/10/05 11:23:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1460966443/002/a23242026/10/05 11:23:11 INFO Uploading batch count=123252026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=12326--- PASS: TestQueueRetryMovesToBack (0.01s)2327--- PASS: TestQueueFetchBatchLimit (0.01s)23282026/10/05 11:23:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1460966443/002/b23292026/10/05 11:23:11 INFO Uploading batch count=12330--- PASS: TestQueueEnqueueAndFetch (0.01s)23312026/10/05 11:23:11 INFO Uploading batch count=123322026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=12333--- PASS: TestQueueRemove (0.01s)23342026/10/05 11:23:11 INFO Uploading batch count=223352026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=223362026/10/05 11:23:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1460966443/002/c23372026/10/05 11:23:11 INFO Uploading batch count=123382026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=12339--- PASS: TestQueueDeduplication (0.01s)23402026/10/05 11:23:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1460966443/002/d23412026/10/05 11:23:11 ERROR Drain finished with paths left in queue remaining=123422026/10/05 11:23:11 INFO Uploading batch count=223432026/10/05 11:23:11 ERROR Upload failed error="upload failed" count=223442026/10/05 11:23:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1460966443/002/e2345--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)23462026/10/05 11:23:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1460966443/002/f23472026/10/05 11:23:11 ERROR Drain finished with paths left in queue remaining=102348--- PASS: TestDrainIsolatesPoisonPath (0.02s)2349--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2350--- PASS: TestWorkerSkipsGCdPaths (0.03s)2351--- PASS: TestWorkerUploadsAndRemoves (0.03s)2352--- PASS: TestWorkerPrunesClosureDeps (0.03s)2353--- PASS: TestQueueRemoveLargeClosure (0.15s)2354--- PASS: TestQueueConcurrentWriters (0.15s)23552026/10/05 11:23:11 ERROR Upload failed error="context deadline exceeded" count=223562026/10/05 11:23:11 ERROR Drain finished with paths left in queue remaining=42357--- PASS: TestDrainTimeout (0.21s)23582026/10/05 11:23:12 INFO Uploading batch count=123592026/10/05 11:23:12 INFO Uploading batch count=123602026/10/05 11:23:12 INFO Uploading batch count=123612026/10/05 11:23:12 ERROR Upload failed error="upload failed" count=123622026/10/05 11:23:12 INFO Uploading batch count=123632026/10/05 11:23:12 ERROR Upload failed error="upload failed" count=123642026/10/05 11:23:12 INFO Uploading batch count=123652026/10/05 11:23:12 ERROR Upload failed error="upload failed" count=123662026/10/05 11:23:12 INFO Uploading batch count=123672026/10/05 11:23:12 ERROR Upload failed error="upload failed" count=123682026/10/05 11:23:12 ERROR Drain finished with paths left in queue remaining=12369--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2370PASS