nixbot

builds

failed niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #368 · 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 TestScriptTokenEmptyToken101=== CONT TestScriptTokenScriptFails102=== CONT TestScriptTokenBadJSON103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess104=== CONT TestDumpPathWriterError1052026/10/06 10:42:40 WARN Rate limiter enabled after throttle name=server-test rate=5106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestRateLimiterFeedback108=== RUN TestRateLimiterFeedback/429_enables_limiter109=== CONT TestScriptTokenNoExpiryRerunsEveryCall110=== CONT TestPathInfoCACompatibility111=== CONT TestFileTokenEmpty112=== CONT TestFileTokenMissing113=== CONT TestParsePathInfoJSONMultiplePaths114=== CONT TestFileTokenReadsAndCaches115=== CONT TestParsePathInfoJSON116=== CONT TestStaticToken117=== CONT TestPathInfoHashCompatibility118=== CONT TestSetClientTLSErrors119=== CONT TestGetStorePathHash120=== CONT TestSetClientTLSDoesNotMutateDefaultTransport121=== CONT TestConvertHashToNix32122=== CONT TestSetClientTLS123=== CONT TestClientSignaturesByStorePath124=== CONT TestEncodeNixBase32WithRealHash125--- PASS: TestScriptTokenScriptFails (0.00s)126=== CONT TestStreamPushReportsSignatures127=== PAUSE TestRateLimiterFeedback/429_enables_limiter128=== RUN TestRateLimiterFeedback/503_enables_limiter129=== RUN TestPathInfoCACompatibility/null_ca_field130--- PASS: TestScriptTokenEmptyToken (0.00s)131=== CONT TestEncodeNixBase32132=== RUN TestEncodeNixBase32/test_string_hash133=== PAUSE TestEncodeNixBase32/test_string_hash134=== RUN TestEncodeNixBase32/empty_input135=== PAUSE TestEncodeNixBase32/empty_input136=== CONT TestStreamPushRequestLine137=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths139=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths140=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths141=== CONT TestStreamPushGivesUpOnDeadServer142--- PASS: TestStaticToken (0.00s)143=== CONT TestShellSplitErrors144--- PASS: TestShellSplitErrors (0.00s)145=== CONT TestShellSplit1462026/10/06 10:42:40 ERROR Upload failed error="connection refused" count=201472026/10/06 10:42:40 ERROR Server seems unavailable, giving up on batch untried=17148=== RUN TestParsePathInfoJSON/Nix_format149=== PAUSE TestParsePathInfoJSON/Nix_format150=== PAUSE TestRateLimiterFeedback/503_enables_limiter151=== RUN TestParsePathInfoJSON/Lix_format152=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter153=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== PAUSE TestParsePathInfoJSON/Lix_format155=== RUN TestParsePathInfoJSON/empty_input156=== PAUSE TestParsePathInfoJSON/empty_input157=== CONT TestStreamPushIsolatesFailures158--- PASS: TestShellSplit (0.01s)159=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)161--- PASS: TestFileTokenMissing (0.01s)162=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter163=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon164=== RUN TestParsePathInfoJSON/whitespace_only165--- PASS: TestFileTokenEmpty (0.01s)166=== CONT TestStreamPushBatchesUnderLoad167--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)168--- PASS: TestFileTokenReadsAndCaches (0.01s)169=== CONT TestResolveStorePath170=== RUN TestConvertHashToNix32/SRI_format_to_Nix32171--- PASS: TestClientSignaturesByStorePath (0.00s)172=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32173=== CONT TestUploadMultipart_PartsInParallel174=== PAUSE TestPathInfoCACompatibility/null_ca_field175=== RUN TestPathInfoCACompatibility/old_string_format_-_text176=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text177=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive178=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive179=== RUN TestPathInfoCACompatibility/new_structured_format_-_text180--- PASS: TestEncodeNixBase32WithRealHash (0.00s)181=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun182=== RUN TestGetStorePathHash/valid_store_path183=== PAUSE TestGetStorePathHash/valid_store_path184=== RUN TestGetStorePathHash/basename_without_hyphen_should_error185=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon186=== RUN TestConvertHashToNix32/already_Nix32_format187=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text1882026/10/06 10:42:40 ERROR Upload failed error=boom count=11892026/10/06 10:42:40 ERROR Upload failed error="bad path" count=3190=== PAUSE TestParsePathInfoJSON/whitespace_only1912026/10/06 10:42:40 ERROR Upload failed error=boom count=1192=== RUN TestParsePathInfoJSON/invalid_JSON193=== PAUSE TestParsePathInfoJSON/invalid_JSON194=== CONT TestFilterOversizedClosures195=== RUN TestFilterOversizedClosures/no_limit_keeps_everything196=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything197=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped198=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped199=== RUN TestFilterOversizedClosures/all_closures_skipped200=== PAUSE TestFilterOversizedClosures/all_closures_skipped201=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica202=== CONT TestEncodeNixBase32/test_string_hash203=== CONT TestEncodeNixBase32/empty_input204=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths205=== RUN TestSetClientTLSErrors/missing_cert_file206=== CONT TestDumpPathMatchesNix207=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2082026/10/06 10:42:40 INFO Garbage collection started209=== CONT TestParsePathInfoJSON/Nix_format210=== CONT TestParsePathInfoJSON/invalid_JSON211=== CONT TestParsePathInfoJSON/whitespace_only212=== CONT TestParsePathInfoJSON/empty_input213=== CONT TestParsePathInfoJSON/Lix_format214=== CONT TestFilterOversizedClosures/no_limit_keeps_everything215=== CONT TestScriptTokenEmptyCommand216=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2172026/10/06 10:42:40 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=2000218=== CONT TestFilterOversizedClosures/all_closures_skipped2192026/10/06 10:42:40 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=50220=== CONT TestDumpPathSingleFile221=== CONT TestDoWithRetry_BodyReplayedViaGetBody2222026/10/06 10:42:40 INFO Garbage collection started223=== RUN TestSetClientTLS/rejects_connection_without_client_cert224=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert225=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA226=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter227=== CONT TestUploadMultipart_SupersededByPeer228=== CONT TestPartSizeForNAR229=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI230=== PAUSE TestConvertHashToNix32/already_Nix32_format231=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== CONT TestStreamPushReportsEveryPath233=== CONT TestRegisterUploadedObjectReusesConnections234=== CONT TestCaseHackSuffix235=== PAUSE TestSetClientTLSErrors/missing_cert_file236=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error237--- PASS: TestScriptTokenBadJSON (0.01s)238=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA239=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI240=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512241=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512242=== RUN TestSetClientTLS/preserves_debug_logging_transport243=== PAUSE TestSetClientTLS/preserves_debug_logging_transport244=== CONT TestRateLimiterFeedback/503_enables_limiter245=== CONT TestSetClientTLS/rejects_connection_without_client_cert246=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter247=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)248=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI250=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon251=== CONT TestSetClientTLS/preserves_debug_logging_transport2522026/10/06 10:42:40 WARN Rate limiter enabled after throttle name=server-test rate=52532026/10/06 10:42:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33143254=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter255=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2562026/10/06 10:42:40 WARN Rate limiter backed off name=server-test rate=52572026/10/06 10:42:40 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:331432582026/10/06 10:42:40 WARN Rate limiter enabled after throttle name=server-test rate=5259--- PASS: TestResolveStorePath (0.00s)2602026/10/06 10:42:40 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=0261--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)2622026/10/06 10:42:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:40899263--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)264--- PASS: TestDoServerRequestAttachesToken (0.04s)265=== RUN TestUploadMultipart_SupersededByPeer/exists266=== RUN TestPartSizeForNAR/zero_stays_at_minimum267=== RUN TestConvertHashToNix32/invalid_format268=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method269=== CONT TestPathInfoCACompatibility/null_ca_field2702026/10/06 10:42:40 WARN Rate limiter backed off name=server-test rate=5271=== CONT TestRateLimiterFeedback/429_enables_limiter272=== RUN TestSetClientTLSErrors/missing_key_file273=== PAUSE TestSetClientTLSErrors/missing_key_file274=== RUN TestSetClientTLSErrors/missing_ca_file275=== PAUSE TestSetClientTLSErrors/missing_ca_file276=== RUN TestSetClientTLSErrors/invalid_ca_file277=== PAUSE TestSetClientTLSErrors/invalid_ca_file278=== CONT TestSetClientTLSErrors/missing_cert_file279=== CONT TestSetClientTLSErrors/invalid_ca_file280=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error281=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error282=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error283=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error284=== CONT TestGetStorePathHash/valid_store_path285=== CONT TestSetClientTLSErrors/missing_ca_file286=== CONT TestSetClientTLSErrors/missing_key_file287=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error288=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error289=== CONT TestGetStorePathHash/basename_without_hyphen_should_error2902026/10/06 10:42:40 WARN Garbage collection finished on another replica. Its statistics are not available here291=== CONT TestPathInfoCACompatibility/new_structured_format_-_text292=== PAUSE TestUploadMultipart_SupersededByPeer/exists293=== RUN TestUploadMultipart_SupersededByPeer/missing294=== PAUSE TestUploadMultipart_SupersededByPeer/missing295=== CONT TestUploadMultipart_SupersededByPeer/exists296=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method297--- PASS: TestStreamPushIsolatesFailures (0.03s)298=== CONT TestPathInfoCACompatibility/old_string_format_-_text299--- PASS: TestStreamPushReportsSignatures (0.03s)300--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)301=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum302=== RUN TestPartSizeForNAR/small_stays_at_minimum303=== PAUSE TestPartSizeForNAR/small_stays_at_minimum304=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum305=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum306=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts307=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts308=== RUN TestPartSizeForNAR/1_TiB309=== PAUSE TestPartSizeForNAR/1_TiB310=== RUN TestPartSizeForNAR/5_TiB_S3_max_object311=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object312=== RUN TestPartSizeForNAR/capped_at_5_GiB313=== PAUSE TestPartSizeForNAR/capped_at_5_GiB314=== CONT TestPartSizeForNAR/zero_stays_at_minimum315=== CONT TestPartSizeForNAR/capped_at_5_GiB316=== CONT TestPartSizeForNAR/5_TiB_S3_max_object317=== CONT TestPartSizeForNAR/1_TiB318=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum319=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive320=== PAUSE TestConvertHashToNix32/invalid_format3212026/10/06 10:42:40 WARN Rate limiter enabled after throttle name=server-test rate=5322=== CONT TestConvertHashToNix32/SRI_format_to_Nix323232026/10/06 10:42:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34755324=== CONT TestPartSizeForNAR/small_stays_at_minimum325=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts326--- PASS: TestPartSizeForNAR (0.01s)327 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)328 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)329 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)330 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)331 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)332 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)333 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)334=== CONT TestConvertHashToNix32/invalid_format335=== CONT TestConvertHashToNix32/already_Nix32_format336--- PASS: TestConvertHashToNix32 (0.05s)337 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)338 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)339 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)3402026/10/06 10:42:40 WARN Rate limiter backed off name=server-test rate=5341=== CONT TestUploadMultipart_SupersededByPeer/missing342--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)343 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)344 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)345--- PASS: TestEncodeNixBase32 (0.00s)346 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)347 --- PASS: TestEncodeNixBase32/empty_input (0.00s)348--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)349 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)350 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)351--- PASS: TestParsePathInfoJSON (0.04s)352 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)353 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)354 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)355 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)356 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)357--- PASS: TestScriptTokenEmptyCommand (0.00s)358--- PASS: TestFilterOversizedClosures (0.00s)359 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)360 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)361 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)362--- PASS: TestStreamPushReportsEveryPath (0.00s)363--- PASS: TestPathInfoHashCompatibility (0.03s)364 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)365 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)366 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)367 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)368--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)369--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)370--- PASS: TestRateLimiterFeedback (0.04s)371 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)374 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)375--- PASS: TestSetClientTLSErrors (0.04s)376 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)377 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)380--- PASS: TestGetStorePathHash (0.03s)381 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)382 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)383 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)384 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)385--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)386--- PASS: TestPathInfoCACompatibility (0.04s)387 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)388 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)389 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)390 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)391 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)3922026/10/06 10:42:40 http: TLS handshake error from 127.0.0.1:38322: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.03s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestStreamPushRequestLine (0.07s)398--- PASS: TestDumpPathSingleFile (0.03s)399--- PASS: TestCaseHackSuffix (0.03s)400--- PASS: TestDumpPathWriterError (0.08s)401--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.08s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)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/postgres901321053/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/postgres901321053/data -l logfile start434435/build/postgres901321053:5432 - no response4362026-10-06 10:42:42.132 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 10:42:42.133 UTC [128] LOG: listening on Unix socket "/build/postgres901321053/.s.PGSQL.5432"4382026-10-06 10:42:42.137 UTC [135] LOG: database system was shut down at 2026-10-06 10:42:41 UTC4392026-10-06 10:42:42.141 UTC [128] LOG: database system is ready to accept connections440/build/postgres901321053: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/06 10:42:42 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 10:42:43 INFO lead: released remote=192.0.2.1:12344882026/10/06 10:42:43 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 10:42:44 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/06 10:42:44 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 10:42:45.770 UTC [385] FATAL: terminating connection due to administrator command4982026/10/06 10:42:45 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 10:42:46 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 10:42:46 INFO lead: released remote=192.0.2.1:12345012026/10/06 10:42:47 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 TestReadProxyContentNegotiation604=== PAUSE TestReadProxyContentNegotiation605=== RUN TestReadProxyNarStreaming606=== PAUSE TestReadProxyNarStreaming607=== RUN TestReadProxy404608=== PAUSE TestReadProxy404609=== RUN TestReadProxyInvalidPath610=== PAUSE TestReadProxyInvalidPath611=== RUN TestReadProxyHead612=== PAUSE TestReadProxyHead613=== RUN TestReadProxyOutlastsServerWriteTimeout614=== PAUSE TestReadProxyOutlastsServerWriteTimeout615=== RUN TestReadProxyConditionalGet616=== PAUSE TestReadProxyConditionalGet617=== RUN TestReadProxyRootRedirectsToIndexHTML618=== PAUSE TestReadProxyRootRedirectsToIndexHTML619=== RUN TestReadProxyDisabled620=== PAUSE TestReadProxyDisabled621=== RUN TestReadRedirectNar622=== PAUSE TestReadRedirectNar623=== RUN TestReadRedirectKeepsNarinfoProxied624=== PAUSE TestReadRedirectKeepsNarinfoProxied625=== RUN TestReadProxyRangeRequest626=== PAUSE TestReadProxyRangeRequest627=== RUN TestReadRedirectUsesPublicS3URL628=== PAUSE TestReadRedirectUsesPublicS3URL629=== RUN TestPush_OverlappingRootsStoreOneRowPerKey630=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey631=== RUN TestPush_CompleteCommitsEveryRoot632=== PAUSE TestPush_CompleteCommitsEveryRoot633=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit634=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit635=== RUN TestPush_RejectsBadRequests636=== PAUSE TestPush_RejectsBadRequests637=== RUN TestPush_SignsNarinfosOfItsPendingObjects638=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects639=== RUN TestRedundantMultipartUpload640=== PAUSE TestRedundantMultipartUpload641=== RUN TestCompleteMultipartUpload_ErrorButObjectExists642=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists643=== RUN TestCompletedNarNotReofferedAcrossClosures644=== PAUSE TestCompletedNarNotReofferedAcrossClosures645=== RUN TestPresignedUploadRegisteredBeforeCommit646=== PAUSE TestPresignedUploadRegisteredBeforeCommit647=== RUN TestService_Rustfstest648=== PAUSE TestService_Rustfstest649=== RUN TestParseSize650=== PAUSE TestParseSize651=== RUN TestSkippedUploadsHandler652=== PAUSE TestSkippedUploadsHandler653=== RUN TestSystemdListenerNotActivated654--- PASS: TestSystemdListenerNotActivated (0.00s)655=== RUN TestWatchdogBeatsWhenHealthy656--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)657=== RUN TestWatchdogSkipsWhenUnhealthy6582026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:42:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"668--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)669=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== RUN TestProxyWriteTimeout672=== PAUSE TestProxyWriteTimeout673=== RUN TestPendingClosureWriteTimeout674=== PAUSE TestPendingClosureWriteTimeout675=== RUN TestIsValidUploadKey676=== PAUSE TestIsValidUploadKey677=== RUN TestUploadHandlersRejectInvalidKeys678=== PAUSE TestUploadHandlersRejectInvalidKeys679=== RUN TestUploadHandlersRejectOversizedBody680=== PAUSE TestUploadHandlersRejectOversizedBody681=== RUN TestService_cleanupPendingClosuresHandler682=== PAUSE TestService_cleanupPendingClosuresHandler683=== RUN TestService_createPendingClosureHandler684=== PAUSE TestService_createPendingClosureHandler685=== RUN TestService_verifyS3Integrity686=== PAUSE TestService_verifyS3Integrity687=== RUN TestCompleteMultipartUnregistered688=== PAUSE TestCompleteMultipartUnregistered689=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT690=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT691=== CONT TestProxyWriteTimeout692=== CONT TestPendingCleanupUsesOneCutoff693=== RUN TestProxyWriteTimeout/narinfo694=== PAUSE TestProxyWriteTimeout/narinfo695=== CONT TestService_AuthMiddleware696=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded697=== CONT TestMultipartCleanup698=== CONT TestServerTLSConfig699=== RUN TestServerTLSConfig/no_client_CA700=== CONT TestService_NativeMTLS701=== CONT TestMetricsInventory702=== CONT TestNARDeduplicationMetadataUploadBug703=== CONT TestCreatePendingClosureRejectsOversizedNAR704=== CONT TestCacheConfigHandlerMaxNarSize7052026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures706=== CONT TestGenerateLandingPage707=== CONT TestCommitRacingPendingCleanupKeepsObjects708=== CONT TestReadProxyRootRedirectsToIndexHTML709=== CONT TestService_healthCheckHandler710=== CONT TestGracefulShutdownDrainsInflight711=== CONT TestGCTaskStore_Fail712=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle713=== CONT TestGCTaskStore_PhaseUpdates7142026/10/06 10:42:47 INFO Starting HTTP server address=127.0.0.1:39803715=== CONT TestSkippedUploadsHandler716=== CONT TestGCTaskStore_CompletedAllowsNewTask717=== CONT TestPushWaitsForSweepHoldingRow7182026/10/06 10:42:47 INFO Shutdown signal received, draining in-flight requests timeout=10s719=== CONT TestGCTaskStore_GetReturnsLatest720=== CONT TestParseSize721=== CONT TestSweepRechecksPendingAfterLocking7222026/10/06 10:42:47 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000723=== CONT TestGCTaskStore_GetEmpty724=== CONT TestService_Rustfstest725=== CONT TestGCTaskStore_ConflictDifferentParams726=== CONT TestGetExistingObjectsLocksRows727=== CONT TestGCTaskStore_DeduplicateSameParams728=== CONT TestPresignedUploadRegisteredBeforeCommit729=== CONT TestGCTaskStore_StartNew730=== CONT TestRegisterCompletedObjectNeedsPendingRow731=== CONT TestGCEndsOnShutdown732=== RUN TestGCEndsOnShutdown/before_the_run733=== PAUSE TestGCEndsOnShutdown/before_the_run734=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete735=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete736=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark737=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark738=== CONT TestCompletedNarNotReofferedAcrossClosures739=== RUN TestProxyWriteTimeout/1_GiB_nar740=== PAUSE TestProxyWriteTimeout/1_GiB_nar741=== RUN TestProxyWriteTimeout/10_GiB_nar742=== PAUSE TestProxyWriteTimeout/10_GiB_nar743=== RUN TestProxyWriteTimeout/unknown_size744=== PAUSE TestProxyWriteTimeout/unknown_size745=== PAUSE TestServerTLSConfig/no_client_CA746=== RUN TestServerTLSConfig/missing_CA_file747=== PAUSE TestServerTLSConfig/missing_CA_file748=== RUN TestServerTLSConfig/not_a_PEM_file749--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)750--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)751--- PASS: TestGCTaskStore_Fail (0.00s)752--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)753--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)754--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)755--- PASS: TestParseSize (0.00s)756=== CONT TestSweepSkipsRowsLockedByPush757=== CONT TestService_readinessHandler758=== CONT TestCompleteMultipartUpload_ErrorButObjectExists759=== PAUSE TestServerTLSConfig/not_a_PEM_file760--- PASS: TestGCTaskStore_GetEmpty (0.00s)761--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)762--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)763--- PASS: TestGCTaskStore_StartNew (0.00s)764--- PASS: TestGenerateLandingPage (0.00s)765=== CONT TestFailedS3DeleteKeepsTombstone766--- PASS: TestSkippedUploadsHandler (0.01s)767=== CONT TestRedundantMultipartUpload768--- PASS: TestGracefulShutdownDrainsInflight (0.07s)769=== CONT TestPush_SignsNarinfosOfItsPendingObjects7702026/10/06 10:42:47 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"771--- PASS: TestService_AuthMiddleware (0.25s)772=== CONT TestClientPushesUseOnePush7732026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures7742026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures7752026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures7762026/10/06 10:42:47 INFO Received cleanup request method=DELETE path=/api/pending_closures777--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.31s)778=== CONT TestPush_RejectsBadRequests7792026/10/06 10:42:47 INFO Aborted multipart uploads count=0 kept=07802026/10/06 10:42:47 WARN Force mode enabled - objects will be deleted immediately without grace period7812026/10/06 10:42:47 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=07822026/10/06 10:42:47 INFO Vacuumed table table=pending_closures7832026/10/06 10:42:47 INFO Vacuumed table table=pending_objects7842026/10/06 10:42:47 INFO Vacuumed table table=multipart_uploads7852026/10/06 10:42:47 INFO Vacuumed table table=closures7862026/10/06 10:42:47 INFO Vacuumed table table=objects7872026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures7882026/10/06 10:42:47 INFO Aborted multipart uploads count=0 kept=07892026/10/06 10:42:47 WARN Force mode enabled - objects will be deleted immediately without grace period7902026/10/06 10:42:47 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=07912026/10/06 10:42:47 INFO Vacuumed table table=pending_closures7922026/10/06 10:42:47 INFO Vacuumed table table=pending_objects7932026/10/06 10:42:47 INFO Vacuumed table table=multipart_uploads7942026/10/06 10:42:47 INFO Vacuumed table table=closures7952026/10/06 10:42:47 INFO Vacuumed table table=objects796--- PASS: TestSweepSkipsRowsLockedByPush (0.35s)797=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit7982026/10/06 10:42:47 INFO Aborted multipart uploads count=0 kept=07992026/10/06 10:42:47 WARN Force mode enabled - objects will be deleted immediately without grace period8002026/10/06 10:42:47 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=08012026/10/06 10:42:47 INFO Vacuumed table table=pending_closures8022026/10/06 10:42:47 INFO Vacuumed table table=pending_objects8032026/10/06 10:42:47 INFO Vacuumed table table=multipart_uploads8042026/10/06 10:42:47 INFO Vacuumed table table=closures8052026/10/06 10:42:47 INFO Vacuumed table table=objects8062026/10/06 10:42:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8072026/10/06 10:42:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"808--- PASS: TestService_NativeMTLS (0.38s)809=== CONT TestPinProtectsFromGC810--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.38s)811=== CONT TestPush_CompleteCommitsEveryRoot812=== NAME TestNARDeduplicationMetadataUploadBug813 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3996842330/001/store/n88fz1q1fq145wkf08n86ngazqky72bm-file1.txt814--- PASS: TestMetricsInventory (0.41s)815=== CONT TestClientSharedPathCommittedMidPush8162026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures8172026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures8182026/10/06 10:42:47 INFO Received cleanup request method=DELETE path=/api/pending_closures8192026/10/06 10:42:47 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket7/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8202026/10/06 10:42:47 INFO Aborted multipart uploads count=0 kept=18212026/10/06 10:42:47 WARN readiness check failed error="closed pool"822--- PASS: TestService_readinessHandler (0.45s)823=== CONT TestPush_OverlappingRootsStoreOneRowPerKey8242026/10/06 10:42:47 INFO Received cleanup request method=DELETE path=/api/pending_closures8252026/10/06 10:42:47 INFO Aborted multipart uploads count=1 kept=0826--- PASS: TestMultipartCleanup (0.47s)827=== CONT TestClientWithDependencies8282026/10/06 10:42:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8292026/10/06 10:42:47 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLmZkM2FlYzE5LTgyOGQtNDkxYi04NjZmLWM5OWI0NDI4NWQ3NXgxNzkxMjgzMzY3ODQ0Njk3NTcx8302026/10/06 10:42:47 INFO Received push request method=POST path=/api/pushes8312026/10/06 10:42:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLmZkM2FlYzE5LTgyOGQtNDkxYi04NjZmLWM5OWI0NDI4NWQ3NXgxNzkxMjgzMzY3ODQ0Njk3NTcx parts=1832--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.48s)833=== CONT TestReadRedirectUsesPublicS3URL8342026/10/06 10:42:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8352026/10/06 10:42:47 INFO Uploading n88fz1q1fq145wkf08n86ngazqky72bm-file1.txt (160B)836--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.48s)837=== CONT TestClientMultipleUploads8382026/10/06 10:42:47 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8392026/10/06 10:42:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8402026/10/06 10:42:47 WARN Failed to register uploaded object key=n88fz1q1fq145wkf08n86ngazqky72bm.ls error="server returned 404: 404 page not found\n"8412026/10/06 10:42:47 INFO Signed narinfos id=1 count=18422026/10/06 10:42:47 INFO Uploading 1 narinfos8432026/10/06 10:42:47 INFO Received complete push request method=POST path=/api/pushes/1/complete8442026/10/06 10:42:47 WARN Failed to register uploaded object key=n88fz1q1fq145wkf08n86ngazqky72bm.narinfo error="server returned 404: 404 page not found\n"8452026/10/06 10:42:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8462026/10/06 10:42:47 INFO Upload complete. (59ms)847=== NAME TestNARDeduplicationMetadataUploadBug848 metadata_upload_test.go:54: Retrieved narinfo from S3:849 StorePath: /build/TestNARDeduplicationMetadataUploadBug3996842330/001/store/n88fz1q1fq145wkf08n86ngazqky72bm-file1.txt850 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst851 Compression: zstd852 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf853 NarSize: 160854 References: 855 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf8562026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures857 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)858 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):859 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}8602026/10/06 10:42:47 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8612026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures862--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.52s)863=== CONT TestClientFallsBackToClosures8642026/10/06 10:42:47 INFO Aborted multipart uploads count=0 kept=0865=== NAME TestNARDeduplicationMetadataUploadBug866 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3996842330/001/store/p5di9k8hi8bv3s2s8fi8pfi9vh0wab1l-file2.txt8672026/10/06 10:42:47 WARN Force mode enabled - objects will be deleted immediately without grace period8682026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures8692026/10/06 10:42:47 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=08702026/10/06 10:42:47 INFO Vacuumed table table=pending_closures8712026/10/06 10:42:47 INFO Received uploads request method=POST path=/api/pending_closures8722026/10/06 10:42:47 INFO Vacuumed table table=pending_objects8732026/10/06 10:42:47 INFO Vacuumed table table=multipart_uploads8742026/10/06 10:42:47 INFO Vacuumed table table=closures8752026/10/06 10:42:47 INFO Vacuumed table table=objects876--- PASS: TestSweepRechecksPendingAfterLocking (0.56s)877=== CONT TestClientIntegration878--- PASS: TestService_Rustfstest (0.58s)879=== CONT TestForceGCDuringPushOffersSweptObject880=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows881=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows882=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check883=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check884=== CONT TestClientErrorHandling885=== RUN TestClientErrorHandling/InvalidStorePath886=== PAUSE TestClientErrorHandling/InvalidStorePath887=== RUN TestClientErrorHandling/InvalidAuthToken888=== PAUSE TestClientErrorHandling/InvalidAuthToken889=== RUN TestClientErrorHandling/ServerNotAvailable890=== PAUSE TestClientErrorHandling/ServerNotAvailable891=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection892--- PASS: TestService_healthCheckHandler (0.60s)893=== CONT TestReadProxyRangeRequest8942026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes8952026/10/06 10:42:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)8962026/10/06 10:42:48 WARN Failed to register uploaded object key=p5di9k8hi8bv3s2s8fi8pfi9vh0wab1l.ls error="server returned 404: 404 page not found\n"8972026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign8982026/10/06 10:42:48 INFO Signed narinfos id=2 count=18992026/10/06 10:42:48 INFO Uploading 1 narinfos9002026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/2/complete9012026/10/06 10:42:48 WARN Failed to register uploaded object key=p5di9k8hi8bv3s2s8fi8pfi9vh0wab1l.narinfo error="server returned 404: 404 page not found\n"9022026/10/06 10:42:48 INFO Upload complete. (55ms)903=== NAME TestNARDeduplicationMetadataUploadBug904 metadata_upload_test.go:76: Retrieved narinfo from S3:905 StorePath: /build/TestNARDeduplicationMetadataUploadBug3996842330/001/store/p5di9k8hi8bv3s2s8fi8pfi9vh0wab1l-file2.txt906 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst907 Compression: zstd908 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf909 NarSize: 160910 References: 911 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf912--- PASS: TestGetExistingObjectsLocksRows (0.63s)913=== CONT TestGCSweepDeliversEachKeyOnce914=== NAME TestNARDeduplicationMetadataUploadBug915 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)916 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):917 {"version":1,"root":{"type":"regular","size":44}}9182026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures919--- PASS: TestNARDeduplicationMetadataUploadBug (0.63s)920=== CONT TestClientCADerivations9212026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=09222026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period9232026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures9242026/10/06 10:42:48 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9252026/10/06 10:42:48 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."926--- PASS: TestFailedS3DeleteKeepsTombstone (0.64s)927=== CONT TestReadRedirectKeepsNarinfoProxied928--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.65s)929=== CONT TestTombstonedObjectOfferedWithoutWaiting9302026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes9312026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9322026/10/06 10:42:48 INFO Signed narinfos id=1 count=19332026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9342026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9352026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures9362026/10/06 10:42:48 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9372026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9382026/10/06 10:42:48 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9392026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9402026/10/06 10:42:48 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19412026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9422026/10/06 10:42:48 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo943--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.62s)944=== CONT TestReadRedirectNar945=== RUN TestPush_RejectsBadRequests/no_roots946=== PAUSE TestPush_RejectsBadRequests/no_roots947=== RUN TestPush_RejectsBadRequests/no_objects948=== PAUSE TestPush_RejectsBadRequests/no_objects949=== RUN TestPush_RejectsBadRequests/bad_root950=== PAUSE TestPush_RejectsBadRequests/bad_root951=== RUN TestPush_RejectsBadRequests/root_not_in_objects952=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects953=== CONT TestCacheStatsHandler9542026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes9552026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete9562026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes9572026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes9582026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete959--- PASS: TestPush_CompleteCommitsEveryRoot (0.45s)960=== CONT TestReadProxyDisabled9612026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes9622026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=09632026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period964=== NAME TestPinProtectsFromGC965 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4184188803/001/store/c93pd5dh3sy3vn0p9y18ad6a601rmdfp-pinned-file.txt966 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4184188803/001/store/ljz67lb90psysl9hnm0k3rdk38h5lhzx-unpinned-file.txt9672026/10/06 10:42:48 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=0968--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.41s)969=== CONT TestCacheConfigHandler970=== RUN TestCacheConfigHandler/full_config,_no_issuer971=== PAUSE TestCacheConfigHandler/full_config,_no_issuer972=== RUN TestCacheConfigHandler/no_cache_url_configured973=== PAUSE TestCacheConfigHandler/no_cache_url_configured974=== RUN TestCacheConfigHandler/no_signing_keys975=== PAUSE TestCacheConfigHandler/no_signing_keys976=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator977=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator978=== CONT TestGCSweepSkipsPendingObjects9792026/10/06 10:42:48 INFO Vacuumed table table=pending_closures9802026/10/06 10:42:48 INFO Vacuumed table table=pending_objects9812026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads9822026/10/06 10:42:48 INFO Vacuumed table table=closures9832026/10/06 10:42:48 INFO Vacuumed table table=objects9842026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/2/complete985--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.53s)986=== CONT TestService_ReadAuthMiddleware9872026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes9882026/10/06 10:42:48 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9892026/10/06 10:42:48 INFO Uploading 71xbwsdvsbv7gibip0drp446gilzf8hv-shared-dep (136B)9902026/10/06 10:42:48 INFO Uploading rcj0n8hliyf9p962lyhyzywjbak5jyrg-b (216B)991--- PASS: TestReadRedirectUsesPublicS3URL (0.42s)992=== CONT TestDeduplicatedObjectsRecordedAsPending9932026/10/06 10:42:48 WARN Failed to register uploaded object key=71xbwsdvsbv7gibip0drp446gilzf8hv.ls error="server returned 404: 404 page not found\n"9942026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9952026/10/06 10:42:48 WARN Failed to register uploaded object key=88hrkamp4jnlcb008d5lnrn17vmkk1al.ls error="server returned 404: 404 page not found\n"9962026/10/06 10:42:48 WARN Failed to register uploaded object key=rcj0n8hliyf9p962lyhyzywjbak5jyrg.ls error="server returned 404: 404 page not found\n"9972026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9982026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/035zwxq4l6dn0rwsn76gvkq8fc1nclwdc1lx5mqgjphqznh9vikx.nar.zst error="server returned 404: 404 page not found\n"9992026/10/06 10:42:48 INFO Signed narinfos id=1 count=310002026/10/06 10:42:48 INFO Uploading 3 narinfos10012026/10/06 10:42:48 WARN Failed to register uploaded object key=88hrkamp4jnlcb008d5lnrn17vmkk1al.narinfo error="server returned 404: 404 page not found\n"10022026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete10032026/10/06 10:42:48 WARN Failed to register uploaded object key=71xbwsdvsbv7gibip0drp446gilzf8hv.narinfo error="server returned 404: 404 page not found\n"10042026/10/06 10:42:48 WARN Failed to register uploaded object key=rcj0n8hliyf9p962lyhyzywjbak5jyrg.narinfo error="server returned 404: 404 page not found\n"10052026/10/06 10:42:48 INFO Upload complete. (60ms)1006=== NAME TestClientPushesUseOnePush1007 client_pushes_test.go:97: Retrieved narinfo from S3:1008 StorePath: /build/TestClientPushesUseOnePush3654650060/001/store/71xbwsdvsbv7gibip0drp446gilzf8hv-shared-dep1009 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1010 Compression: zstd1011 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821012 NarSize: 1361013 References: 1014 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1015 client_pushes_test.go:97: Retrieved narinfo from S3:1016 StorePath: /build/TestClientPushesUseOnePush3654650060/001/store/88hrkamp4jnlcb008d5lnrn17vmkk1al-a1017 URL: nar/035zwxq4l6dn0rwsn76gvkq8fc1nclwdc1lx5mqgjphqznh9vikx.nar.zst1018 Compression: zstd1019 NarHash: sha256:035zwxq4l6dn0rwsn76gvkq8fc1nclwdc1lx5mqgjphqznh9vikx1020 NarSize: 2161021 References: /build/TestClientPushesUseOnePush3654650060/001/store/71xbwsdvsbv7gibip0drp446gilzf8hv-shared-dep1022 CA: text:sha256:1lskzf4hrwvm3axn2r4byf3774s3ncq7wvqg1zds88x29qh1jxga1023 client_pushes_test.go:97: Retrieved narinfo from S3:1024 StorePath: /build/TestClientPushesUseOnePush3654650060/001/store/rcj0n8hliyf9p962lyhyzywjbak5jyrg-b1025 URL: nar/035zwxq4l6dn0rwsn76gvkq8fc1nclwdc1lx5mqgjphqznh9vikx.nar.zst1026 Compression: zstd1027 NarHash: sha256:035zwxq4l6dn0rwsn76gvkq8fc1nclwdc1lx5mqgjphqznh9vikx1028 NarSize: 2161029 References: /build/TestClientPushesUseOnePush3654650060/001/store/71xbwsdvsbv7gibip0drp446gilzf8hv-shared-dep1030 CA: text:sha256:1lskzf4hrwvm3axn2r4byf3774s3ncq7wvqg1zds88x29qh1jxga10312026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes1032--- PASS: TestClientPushesUseOnePush (0.69s)1033=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10342026/10/06 10:42:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10352026/10/06 10:42:48 INFO Uploading c93pd5dh3sy3vn0p9y18ad6a601rmdfp-pinned-file.txt (128B)10362026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10372026/10/06 10:42:48 WARN Failed to register uploaded object key=c93pd5dh3sy3vn0p9y18ad6a601rmdfp.ls error="server returned 404: 404 page not found\n"10382026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10392026/10/06 10:42:48 INFO Signed narinfos id=1 count=110402026/10/06 10:42:48 INFO Uploading 1 narinfos1041=== NAME TestClientMultipleUploads1042 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2637890590/001/store/12w7csdp5s7w0sd3v7npb1v2bv8j06ap-test-file-0.txt10432026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete10442026/10/06 10:42:48 WARN Failed to register uploaded object key=c93pd5dh3sy3vn0p9y18ad6a601rmdfp.narinfo error="server returned 404: 404 page not found\n"1045=== NAME TestClientWithDependencies1046 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies313155823/001/store/v72b1fx3dwy7dn8k5s062k4jp7m63hs9-test-script10472026/10/06 10:42:48 INFO Upload complete. (69ms)10482026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures10492026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes10502026/10/06 10:42:48 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10512026/10/06 10:42:48 INFO Uploading hx0c2qvgy7jz9h5lkhm19gcacgg42654-shared-dep (136B)10522026/10/06 10:42:48 INFO Uploading 0912c5fjkh06bm26yvg28wyb8if020la-top (224B)1053=== NAME TestClientMultipleUploads1054 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2637890590/001/store/rcww81d2535vkwfw9l13kk1nivznq9wb-test-file-1.txt1055=== NAME TestClientWithDependencies1056 client_integration_test.go:615: Found 1 dependencies (including self)10572026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/0hwn6r0wrssy16v2rdmj8rxbdd2s1w56wq99v0n2s5xj16lg66lg.nar.zst error="server returned 404: 404 page not found\n"10582026/10/06 10:42:48 WARN Failed to register uploaded object key=hx0c2qvgy7jz9h5lkhm19gcacgg42654.ls error="server returned 404: 404 page not found\n"10592026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10602026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10612026/10/06 10:42:48 WARN Failed to register uploaded object key=0912c5fjkh06bm26yvg28wyb8if020la.ls error="server returned 404: 404 page not found\n"10622026/10/06 10:42:48 INFO Signed narinfos id=1 count=210632026/10/06 10:42:48 INFO Uploading 2 narinfos1064=== NAME TestClientIntegration1065 client_integration_test.go:286: Created store path: /build/TestClientIntegration1429548083/002/store/lzhl3b4cidk2fjspsrq8cx1x3vkvfz61-test-file.txt10662026/10/06 10:42:48 WARN Failed to register uploaded object key=0912c5fjkh06bm26yvg28wyb8if020la.narinfo error="server returned 404: 404 page not found\n"10672026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete10682026/10/06 10:42:48 WARN Failed to register uploaded object key=hx0c2qvgy7jz9h5lkhm19gcacgg42654.narinfo error="server returned 404: 404 page not found\n"10692026/10/06 10:42:48 INFO Upload complete. (61ms)1070=== NAME TestClientSharedPathCommittedMidPush1071 client_integration_test.go:680: Retrieved narinfo from S3:1072 StorePath: /build/TestClientSharedPathCommittedMidPush843157292/001/store/hx0c2qvgy7jz9h5lkhm19gcacgg42654-shared-dep1073 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1074 Compression: zstd1075 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821076 NarSize: 1361077 References: 1078 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1079 client_integration_test.go:680: Retrieved narinfo from S3:1080 StorePath: /build/TestClientSharedPathCommittedMidPush843157292/001/store/0912c5fjkh06bm26yvg28wyb8if020la-top1081 URL: nar/0hwn6r0wrssy16v2rdmj8rxbdd2s1w56wq99v0n2s5xj16lg66lg.nar.zst1082 Compression: zstd1083 NarHash: sha256:0hwn6r0wrssy16v2rdmj8rxbdd2s1w56wq99v0n2s5xj16lg66lg1084 NarSize: 2241085 References: /build/TestClientSharedPathCommittedMidPush843157292/001/store/hx0c2qvgy7jz9h5lkhm19gcacgg42654-shared-dep1086 CA: text:sha256:1fq0q8zlra7zp1p64cjbdm1kr73dgjwps1mxx79s68n5gf02s63i1087--- PASS: TestClientSharedPathCommittedMidPush (0.60s)1088=== CONT TestService_AuthMiddleware_MTLSProxyHeader1089--- PASS: TestReadProxyRangeRequest (0.42s)1090=== CONT TestLeadEndsOnShutdown10912026/10/06 10:42:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10922026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes1093=== NAME TestClientMultipleUploads1094 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2637890590/001/store/jinh77fzdafr91xq5nz18v70k4609va2-test-file-2.txt10952026/10/06 10:42:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10962026/10/06 10:42:48 INFO Uploading ljz67lb90psysl9hnm0k3rdk38h5lhzx-unpinned-file.txt (128B)10972026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10982026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10992026/10/06 10:42:48 WARN Failed to register uploaded object key=ljz67lb90psysl9hnm0k3rdk38h5lhzx.ls error="server returned 404: 404 page not found\n"11002026/10/06 10:42:48 INFO Signed narinfos id=2 count=111012026/10/06 10:42:48 INFO Uploading 1 narinfos11022026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/2/complete11032026/10/06 10:42:48 WARN Failed to register uploaded object key=ljz67lb90psysl9hnm0k3rdk38h5lhzx.narinfo error="server returned 404: 404 page not found\n"11042026/10/06 10:42:48 INFO Upload complete. (43ms)11052026/10/06 10:42:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLjM0NjVjNWRiLWZmNmQtNGQwNy04NWU3LWYxM2MxOTU1NDM1NHgxNzkxMjgzMzY4MDM3ODEyMzQ1 parts=1211062026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures1107--- PASS: TestPushWaitsForSweepHoldingRow (1.04s)1108=== CONT TestLeadIncumbentAnnouncesAtOnce11092026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=011102026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period11122026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes11132026/10/06 10:42:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures11142026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes11152026/10/06 10:42:48 INFO Garbage collection started1116--- PASS: TestReadRedirectKeepsNarinfoProxied (0.42s)1117=== CONT TestPushDedupSurvivesConcurrentGC11182026/10/06 10:42:48 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=011192026/10/06 10:42:48 INFO Vacuumed table table=pending_closures11202026/10/06 10:42:48 INFO Vacuumed table table=pending_objects11212026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads11222026/10/06 10:42:48 INFO Vacuumed table table=closures11232026/10/06 10:42:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11242026/10/06 10:42:48 INFO Uploading v72b1fx3dwy7dn8k5s062k4jp7m63hs9-test-script (136B)11252026/10/06 10:42:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11262026/10/06 10:42:48 INFO Uploading lzhl3b4cidk2fjspsrq8cx1x3vkvfz61-test-file.txt (152B)11272026/10/06 10:42:48 INFO Vacuumed table table=objects1128--- PASS: TestGCSweepDeliversEachKeyOnce (0.45s)1129=== CONT TestLeadElectsOneAndHandsOver11302026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11312026/10/06 10:42:48 WARN Failed to register uploaded object key=log/jb83qs7rh801k2bhaqysg2y40y4nn911-test-script.drv error="server returned 404: 404 page not found\n"11322026/10/06 10:42:48 WARN Failed to register uploaded object key=v72b1fx3dwy7dn8k5s062k4jp7m63hs9.ls error="server returned 404: 404 page not found\n"11332026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11342026/10/06 10:42:48 WARN Failed to register uploaded object key=lzhl3b4cidk2fjspsrq8cx1x3vkvfz61.ls error="server returned 404: 404 page not found\n"11352026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11362026/10/06 10:42:48 INFO Signed narinfos id=1 count=111372026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11382026/10/06 10:42:48 INFO Uploading 1 narinfos11392026/10/06 10:42:48 INFO Signed narinfos id=1 count=111402026/10/06 10:42:48 INFO Uploading 1 narinfos11412026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=011422026/10/06 10:42:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11432026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete11442026/10/06 10:42:48 WARN Failed to register uploaded object key=v72b1fx3dwy7dn8k5s062k4jp7m63hs9.narinfo error="server returned 404: 404 page not found\n"11452026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete11462026/10/06 10:42:48 WARN Failed to register uploaded object key=lzhl3b4cidk2fjspsrq8cx1x3vkvfz61.narinfo error="server returned 404: 404 page not found\n"11472026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period11482026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures11492026/10/06 10:42:48 INFO Upload complete. (61ms)11502026/10/06 10:42:48 INFO Upload complete. (74ms)1151--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.44s)1152=== CONT TestService_AuthMiddleware_OIDC1153=== NAME TestClientWithDependencies1154 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies313155823/001/store) requires matching store prefix11552026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes1156--- PASS: TestClientWithDependencies (0.64s)1157=== CONT TestConnectWaitsForAPeerMigration11582026/10/06 10:42:48 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=011592026/10/06 10:42:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11602026/10/06 10:42:48 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLjc5ODY0YmI0LTAxNjktNGM5NC1hY2NlLTU3OTY4MzRkMTFlY3gxNzkxMjgzMzY4MDk5NjUxOTM0 parts=1211612026/10/06 10:42:48 INFO Uploading 12w7csdp5s7w0sd3v7npb1v2bv8j06ap-test-file-0.txt (160B)11622026/10/06 10:42:48 INFO Uploading jinh77fzdafr91xq5nz18v70k4609va2-test-file-2.txt (160B)11632026/10/06 10:42:48 INFO Uploading rcww81d2535vkwfw9l13kk1nivznq9wb-test-file-1.txt (160B)11642026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures11652026/10/06 10:42:48 INFO Vacuumed table table=pending_closures11662026/10/06 10:42:48 WARN Failed to register uploaded object key=jinh77fzdafr91xq5nz18v70k4609va2.ls error="server returned 404: 404 page not found\n"1167--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.11s)1168=== CONT TestGCMetrics11692026/10/06 10:42:48 WARN Failed to register uploaded object key=rcww81d2535vkwfw9l13kk1nivznq9wb.ls error="server returned 404: 404 page not found\n"11702026/10/06 10:42:48 WARN Failed to register uploaded object key=12w7csdp5s7w0sd3v7npb1v2bv8j06ap.ls error="server returned 404: 404 page not found\n"11712026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11722026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11732026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11742026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11752026/10/06 10:42:48 INFO Signed narinfos id=1 count=311762026/10/06 10:42:48 INFO Uploading 3 narinfos11772026/10/06 10:42:48 INFO Vacuumed table table=pending_objects11782026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads11792026/10/06 10:42:48 WARN Failed to register uploaded object key=rcww81d2535vkwfw9l13kk1nivznq9wb.narinfo error="server returned 404: 404 page not found\n"11802026/10/06 10:42:48 WARN Failed to register uploaded object key=12w7csdp5s7w0sd3v7npb1v2bv8j06ap.narinfo error="server returned 404: 404 page not found\n"11812026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete11822026/10/06 10:42:48 WARN Failed to register uploaded object key=jinh77fzdafr91xq5nz18v70k4609va2.narinfo error="server returned 404: 404 page not found\n"11832026/10/06 10:42:48 INFO Vacuumed table table=closures11842026/10/06 10:42:48 INFO Vacuumed table table=objects11852026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures1186--- PASS: TestReadRedirectNar (0.43s)1187=== CONT TestService_RequireScope_OIDC11882026/10/06 10:42:48 INFO Upload complete. (60ms)1189=== NAME TestClientMultipleUploads1190 client_integration_test.go:369: Uploaded 3 paths in 99.574484ms11912026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures11922026/10/06 10:42:48 INFO All 1 paths already cached11932026/10/06 10:42:48 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11942026/10/06 10:42:48 INFO Uploading zp9474ravacy3ld17pj62hrd8ai5w15q-b (216B)11952026/10/06 10:42:48 INFO Uploading nyc2frr75lwghrypgn41claaz7qf7c1f-shared-dep (136B)1196=== NAME TestClientIntegration1197 client_integration_test.go:312: Retrieved narinfo from S3:1198 StorePath: /build/TestClientIntegration1429548083/002/store/lzhl3b4cidk2fjspsrq8cx1x3vkvfz61-test-file.txt1199 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1200 Compression: zstd1201 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11202 NarSize: 1521203 References: 1204 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11205--- PASS: TestClientMultipleUploads (0.65s)1206=== CONT TestResolveDBConnectionString1207=== RUN TestResolveDBConnectionString/flag_wins1208=== PAUSE TestResolveDBConnectionString/flag_wins1209=== RUN TestResolveDBConnectionString/file_when_flag_empty1210=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1211=== RUN TestResolveDBConnectionString/missing_file_is_an_error1212=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1213=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1214=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1215=== RUN TestResolveDBConnectionString/nothing_configured1216=== PAUSE TestResolveDBConnectionString/nothing_configured1217=== CONT TestGCBugBareHashReferences1218=== NAME TestClientCADerivations1219 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations476232661/001/store/l1w6av23g8yngcwrvs6f7v8bcwcym14i-ca-test1220=== NAME TestClientIntegration1221 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1222 client_integration_test.go:313: Decompressed .ls content (64 bytes):1223 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1224 client_integration_test.go:316: Testing garbage collection...12252026/10/06 10:42:48 WARN Failed to register uploaded object key=pby622cgni9yy6nq4kilrbz34ldazlaf.ls error="server returned 404: 404 page not found\n"12262026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12272026/10/06 10:42:48 WARN Failed to register uploaded object key=zp9474ravacy3ld17pj62hrd8ai5w15q.ls error="server returned 404: 404 page not found\n"12282026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/1aicf2hdc61dsq2b2f16fy83b6saijpn72if0q3k3wvsvj6mqg2z.nar.zst error="server returned 404: 404 page not found\n"12292026/10/06 10:42:48 WARN Failed to register uploaded object key=nyc2frr75lwghrypgn41claaz7qf7c1f.ls error="server returned 404: 404 page not found\n"12302026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12312026/10/06 10:42:48 INFO Signed narinfos id=1 count=212322026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12332026/10/06 10:42:48 INFO Signed narinfos id=2 count=212342026/10/06 10:42:48 INFO Uploading 4 narinfos12352026/10/06 10:42:48 WARN Failed to register uploaded object key=nyc2frr75lwghrypgn41claaz7qf7c1f.narinfo error="server returned 404: 404 page not found\n"12362026/10/06 10:42:48 WARN Failed to register uploaded object key=zp9474ravacy3ld17pj62hrd8ai5w15q.narinfo error="server returned 404: 404 page not found\n"12372026/10/06 10:42:48 WARN Failed to register uploaded object key=pby622cgni9yy6nq4kilrbz34ldazlaf.narinfo error="server returned 404: 404 page not found\n"12382026/10/06 10:42:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38977/oidc12392026/10/06 10:42:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12402026/10/06 10:42:48 WARN Failed to register uploaded object key=nyc2frr75lwghrypgn41claaz7qf7c1f.narinfo error="server returned 404: 404 page not found\n"12412026/10/06 10:42:48 INFO Completed upload id=112422026/10/06 10:42:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1243--- PASS: TestCacheStatsHandler (0.41s)1244=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12452026/10/06 10:42:48 INFO Completed upload id=212462026/10/06 10:42:48 INFO Upload complete. (71ms)1247=== NAME TestClientFallsBackToClosures1248 client_pushes_test.go:112: Retrieved narinfo from S3:1249 StorePath: /build/TestClientFallsBackToClosures95596943/001/store/nyc2frr75lwghrypgn41claaz7qf7c1f-shared-dep1250 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1251 Compression: zstd1252 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821253 NarSize: 1361254 References: 1255 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1256 client_pushes_test.go:112: Retrieved narinfo from S3:1257 StorePath: /build/TestClientFallsBackToClosures95596943/001/store/pby622cgni9yy6nq4kilrbz34ldazlaf-a1258 URL: nar/1aicf2hdc61dsq2b2f16fy83b6saijpn72if0q3k3wvsvj6mqg2z.nar.zst1259 Compression: zstd1260 NarHash: sha256:1aicf2hdc61dsq2b2f16fy83b6saijpn72if0q3k3wvsvj6mqg2z1261 NarSize: 2161262 References: /build/TestClientFallsBackToClosures95596943/001/store/nyc2frr75lwghrypgn41claaz7qf7c1f-shared-dep1263 CA: text:sha256:167h4d464rd9hrssdzmnar8gnl0cgc5vsh3c4racz9rjkzw9d4qh1264 client_pushes_test.go:112: Retrieved narinfo from S3:1265 StorePath: /build/TestClientFallsBackToClosures95596943/001/store/zp9474ravacy3ld17pj62hrd8ai5w15q-b1266 URL: nar/1aicf2hdc61dsq2b2f16fy83b6saijpn72if0q3k3wvsvj6mqg2z.nar.zst1267 Compression: zstd1268 NarHash: sha256:1aicf2hdc61dsq2b2f16fy83b6saijpn72if0q3k3wvsvj6mqg2z1269 NarSize: 2161270 References: /build/TestClientFallsBackToClosures95596943/001/store/nyc2frr75lwghrypgn41claaz7qf7c1f-shared-dep1271 CA: text:sha256:167h4d464rd9hrssdzmnar8gnl0cgc5vsh3c4racz9rjkzw9d4qh1272--- PASS: TestReadProxyDisabled (0.33s)1273=== CONT TestGCAdvisoryLockBlocksConcurrentRun1274--- PASS: TestClientFallsBackToClosures (0.64s)1275=== CONT TestReadProxyNarinfo1276=== NAME TestClientCADerivations1277 client_ca_test.go:139: Found 1 dependencies (including self)12782026/10/06 10:42:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures12792026/10/06 10:42:48 INFO Garbage collection started12802026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=012812026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period1282--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.61s)1283=== CONT TestPresentReportsOnlyClosureRoots12842026/10/06 10:42:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36327/oidc12852026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures12862026/10/06 10:42:48 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=012872026/10/06 10:42:48 INFO Vacuumed table table=pending_closures12882026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=012892026/10/06 10:42:48 INFO Vacuumed table table=pending_objects12902026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads1291--- PASS: TestService_ReadAuthMiddleware (0.33s)1292=== CONT TestReadProxyConditionalGet12932026/10/06 10:42:48 INFO Vacuumed table table=closures12942026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period12952026/10/06 10:42:48 INFO Vacuumed table table=objects12962026/10/06 10:42:48 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=012972026/10/06 10:42:48 INFO Vacuumed table table=pending_closures12982026/10/06 10:42:48 INFO Vacuumed table table=pending_objects12992026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads13002026/10/06 10:42:48 INFO Vacuumed table table=closures13012026/10/06 10:42:48 INFO Vacuumed table table=objects13022026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures1303--- PASS: TestGCSweepSkipsPendingObjects (0.38s)1304=== CONT TestParseSingleRange1305=== RUN TestParseSingleRange/none1306=== PAUSE TestParseSingleRange/none1307=== RUN TestParseSingleRange/unknown_unit1308=== PAUSE TestParseSingleRange/unknown_unit1309=== RUN TestParseSingleRange/multi-range_ignored1310=== PAUSE TestParseSingleRange/multi-range_ignored1311=== RUN TestParseSingleRange/malformed_no_dash1312=== PAUSE TestParseSingleRange/malformed_no_dash1313=== RUN TestParseSingleRange/malformed_both_empty1314=== PAUSE TestParseSingleRange/malformed_both_empty1315=== RUN TestParseSingleRange/malformed_end_before_start1316=== PAUSE TestParseSingleRange/malformed_end_before_start1317=== RUN TestParseSingleRange/closed1318=== PAUSE TestParseSingleRange/closed1319=== RUN TestParseSingleRange/open-ended1320=== PAUSE TestParseSingleRange/open-ended1321=== RUN TestParseSingleRange/end_clamped_to_size1322=== PAUSE TestParseSingleRange/end_clamped_to_size1323=== RUN TestParseSingleRange/suffix1324=== PAUSE TestParseSingleRange/suffix1325=== RUN TestParseSingleRange/suffix_exceeds_size1326=== PAUSE TestParseSingleRange/suffix_exceeds_size1327=== RUN TestParseSingleRange/single_byte1328=== PAUSE TestParseSingleRange/single_byte1329=== RUN TestParseSingleRange/start_past_EOF1330=== PAUSE TestParseSingleRange/start_past_EOF1331=== RUN TestParseSingleRange/start_far_past_EOF1332=== PAUSE TestParseSingleRange/start_far_past_EOF1333=== CONT TestService_ReadScope_PublicByDefault1334--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.34s)1335=== CONT TestPresentNotReportedWhileGCDeletesClosure13362026/10/06 10:42:48 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13372026/10/06 10:42:48 WARN mTLS auth: bound subjects configured but subject DN unavailable13382026/10/06 10:42:48 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1339--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1340=== CONT TestProxyHeadersOnlyTrustedOnSocket13412026/10/06 10:42:48 INFO Received push request method=POST path=/api/pushes13422026/10/06 10:42:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13432026/10/06 10:42:48 INFO Uploading l1w6av23g8yngcwrvs6f7v8bcwcym14i-ca-test (144B)13442026/10/06 10:42:48 WARN Failed to register uploaded object key=log/i77fpm1ay0fc6m6p8s11livdm9r3kyif-ca-test.drv error="server returned 404: 404 page not found\n"13452026/10/06 10:42:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13462026/10/06 10:42:48 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13472026/10/06 10:42:48 WARN Failed to register uploaded object key=l1w6av23g8yngcwrvs6f7v8bcwcym14i.ls error="server returned 404: 404 page not found\n"13482026/10/06 10:42:48 INFO Signed narinfos id=1 count=113492026/10/06 10:42:48 INFO Uploading 1 narinfos1350--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.27s)1351=== CONT TestOrphanedObjectsGCStressTest13522026/10/06 10:42:48 INFO Received complete push request method=POST path=/api/pushes/1/complete13532026/10/06 10:42:48 WARN Failed to register uploaded object key=l1w6av23g8yngcwrvs6f7v8bcwcym14i.narinfo error="server returned 404: 404 page not found\n"13542026/10/06 10:42:48 INFO Upload complete. (91ms)1355=== NAME TestClientCADerivations1356 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations476232661/001/store/l1w6av23g8yngcwrvs6f7v8bcwcym14i-ca-test1357 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1358 Compression: zstd1359 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1360 NarSize: 1441361 References: 1362 Deriver: /build/TestClientCADerivations476232661/001/store/i77fpm1ay0fc6m6p8s11livdm9r3kyif-ca-test.drv1363 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1364 client_ca_test.go:185: Checking for realisation files in S3...1365 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1366 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13672026/10/06 10:42:48 INFO lead: acquired remote=192.0.2.1:123413682026/10/06 10:42:48 INFO lead: acquired remote=192.0.2.1:123413692026/10/06 10:42:48 INFO lead: released remote=192.0.2.1:12341370--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.29s)1371=== CONT TestCreatePin_ReservedPins13722026/10/06 10:42:48 INFO Received uploads request method=POST path=/api/pending_closures13732026/10/06 10:42:48 INFO lead: acquired remote=192.0.2.1:12341374=== NAME TestClientCADerivations1375 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1376 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1377 error: binary cache 's3://bucket42?endpoint=http://localhost:43905&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations476232661/001/store'1378 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11379--- PASS: TestClientCADerivations (0.76s)1380=== CONT TestIsValidCachePath1381=== RUN TestIsValidCachePath/narinfo1382=== PAUSE TestIsValidCachePath/narinfo1383=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1384=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1385=== RUN TestIsValidCachePath/nar_zst1386=== PAUSE TestIsValidCachePath/nar_zst1387=== RUN TestIsValidCachePath/nar_xz1388=== PAUSE TestIsValidCachePath/nar_xz1389=== RUN TestIsValidCachePath/nar_bz21390=== PAUSE TestIsValidCachePath/nar_bz21391=== RUN TestIsValidCachePath/nar_uncompressed1392=== PAUSE TestIsValidCachePath/nar_uncompressed1393=== RUN TestIsValidCachePath/ls1394=== PAUSE TestIsValidCachePath/ls1395=== RUN TestIsValidCachePath/log1396=== PAUSE TestIsValidCachePath/log1397=== RUN TestIsValidCachePath/realisation1398=== PAUSE TestIsValidCachePath/realisation1399=== RUN TestIsValidCachePath/nix-cache-info1400=== PAUSE TestIsValidCachePath/nix-cache-info1401=== RUN TestIsValidCachePath/index.html1402=== PAUSE TestIsValidCachePath/index.html1403=== RUN TestIsValidCachePath/traversal_parent1404=== PAUSE TestIsValidCachePath/traversal_parent1405=== RUN TestIsValidCachePath/traversal_in_middle1406=== PAUSE TestIsValidCachePath/traversal_in_middle1407=== RUN TestIsValidCachePath/invalid_char_e1408=== PAUSE TestIsValidCachePath/invalid_char_e1409=== RUN TestIsValidCachePath/invalid_char_u1410=== PAUSE TestIsValidCachePath/invalid_char_u1411=== RUN TestIsValidCachePath/random_path1412=== PAUSE TestIsValidCachePath/random_path1413=== RUN TestIsValidCachePath/empty1414=== PAUSE TestIsValidCachePath/empty1415=== RUN TestIsValidCachePath/leading_slash1416=== PAUSE TestIsValidCachePath/leading_slash1417=== RUN TestIsValidCachePath/wrong_extension1418=== PAUSE TestIsValidCachePath/wrong_extension1419=== RUN TestIsValidCachePath/short_hash1420=== PAUSE TestIsValidCachePath/short_hash1421=== CONT TestService_cleanupPendingClosuresHandler14222026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=014232026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period14242026/10/06 10:42:48 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=014252026/10/06 10:42:48 INFO Vacuumed table table=pending_closures14262026/10/06 10:42:48 INFO Vacuumed table table=pending_objects14272026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads14282026/10/06 10:42:48 INFO Vacuumed table table=closures14292026/10/06 10:42:48 INFO Vacuumed table table=objects1430--- PASS: TestGCMetrics (0.30s)1431=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT14322026/10/06 10:42:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14332026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=014342026/10/06 10:42:48 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLjZlZTViNmU1LTg2MWYtNDYzZC1hZDBjLTBkOTM2OWQxNjA1ZngxNzkxMjgzMzY4NDUyMTQ2Mzgz error="Get \"http://127.0.0.1:1/bucket23/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14352026/10/06 10:42:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLjI5YjFhYTJkLTI1NDAtNGQ1Ni1hMmZiLTc3YzBiYzcwOTE3OXgxNzkxMjgzMzY4NDQ1ODg3MDQ3 parts=1214362026/10/06 10:42:48 INFO Received cleanup request method=DELETE path=/api/pending_closures14372026/10/06 10:42:48 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=014382026/10/06 10:42:48 INFO Aborted multipart uploads count=1 kept=014392026/10/06 10:42:48 INFO Vacuumed table table=pending_closures14402026/10/06 10:42:48 INFO Vacuumed table table=pending_objects14412026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads1442--- PASS: TestRedundantMultipartUpload (1.45s)1443=== CONT TestIsValidUploadKey1444=== RUN TestIsValidUploadKey/narinfo1445=== PAUSE TestIsValidUploadKey/narinfo1446=== RUN TestIsValidUploadKey/nar_zst1447=== PAUSE TestIsValidUploadKey/nar_zst1448=== RUN TestIsValidUploadKey/nar_xz1449=== PAUSE TestIsValidUploadKey/nar_xz1450=== RUN TestIsValidUploadKey/nar_plain1451=== PAUSE TestIsValidUploadKey/nar_plain1452=== RUN TestIsValidUploadKey/listing1453=== PAUSE TestIsValidUploadKey/listing1454=== RUN TestIsValidUploadKey/build_log1455=== PAUSE TestIsValidUploadKey/build_log1456=== RUN TestIsValidUploadKey/build_log_home-manager_file1457=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1458=== RUN TestIsValidUploadKey/build_log_plus_in_name1459=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1460=== RUN TestIsValidUploadKey/build_log_question_mark1461=== PAUSE TestIsValidUploadKey/build_log_question_mark1462=== RUN TestIsValidUploadKey/build_log_equals1463=== PAUSE TestIsValidUploadKey/build_log_equals1464=== RUN TestIsValidUploadKey/realisation1465=== PAUSE TestIsValidUploadKey/realisation1466=== RUN TestIsValidUploadKey/realisation_plus_in_output1467=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1468=== RUN TestIsValidUploadKey/nix-cache-info1469=== PAUSE TestIsValidUploadKey/nix-cache-info1470=== RUN TestIsValidUploadKey/index.html1471=== PAUSE TestIsValidUploadKey/index.html1472=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1473=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1474=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1475=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1476=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1477=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1478=== RUN TestIsValidUploadKey/traversal1479=== PAUSE TestIsValidUploadKey/traversal1480=== RUN TestIsValidUploadKey/traversal_nar1481=== PAUSE TestIsValidUploadKey/traversal_nar1482=== RUN TestIsValidUploadKey/absolute1483=== PAUSE TestIsValidUploadKey/absolute1484=== RUN TestIsValidUploadKey/empty_key1485=== PAUSE TestIsValidUploadKey/empty_key1486=== RUN TestIsValidUploadKey/unknown_type1487=== PAUSE TestIsValidUploadKey/unknown_type1488=== CONT TestCompleteMultipartUnregistered14892026/10/06 10:42:48 INFO Vacuumed table table=closures14902026/10/06 10:42:48 INFO Vacuumed table table=objects14912026/10/06 10:42:48 INFO Aborted multipart uploads count=0 kept=014922026/10/06 10:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period14932026/10/06 10:42:48 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=014942026/10/06 10:42:48 INFO Vacuumed table table=pending_closures14952026/10/06 10:42:48 INFO Vacuumed table table=pending_objects14962026/10/06 10:42:48 INFO Vacuumed table table=multipart_uploads14972026/10/06 10:42:48 INFO Vacuumed table table=closures14982026/10/06 10:42:48 INFO Vacuumed table table=objects1499--- PASS: TestPushDedupSurvivesConcurrentGC (0.40s)1500=== RUN TestService_RequireScope_OIDC/builder_may_write1501=== CONT TestUploadHandlersRejectOversizedBody1502=== PAUSE TestService_RequireScope_OIDC/builder_may_write1503=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1504=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1505=== RUN TestService_RequireScope_OIDC/ops_may_admin1506=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1507=== RUN TestService_RequireScope_OIDC/ops_may_not_write1508=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1509=== RUN TestService_RequireScope_OIDC/reader_may_not_write1510=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1511=== RUN TestService_RequireScope_OIDC/static_token_may_admin1512=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1513=== RUN TestService_RequireScope_OIDC/static_token_may_write1514=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1515=== RUN TestService_RequireScope_OIDC/reader_may_read1516=== PAUSE TestService_RequireScope_OIDC/reader_may_read1517=== RUN TestService_RequireScope_OIDC/writer_implies_read1518=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1519=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1520=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1521=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1522=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1523=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1524=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1525=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1526=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1527=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1528=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1529=== CONT TestReadProxy40415302026/10/06 10:42:48 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"1531--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.33s)1532=== CONT TestUploadHandlersRejectInvalidKeys1533=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1534=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1535=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1536=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1537=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1538=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1539=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1540=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1541=== CONT TestService_verifyS3Integrity1542=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1543=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1544=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1545=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1546=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1547=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1548=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1549=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1550=== CONT TestReadProxyHead1551--- PASS: TestPresentReportsOnlyClosureRoots (0.35s)1552=== CONT TestService_createPendingClosureHandler15532026/10/06 10:42:48 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1554--- PASS: TestReadProxyNarinfo (0.39s)1555=== CONT TestReadProxyInvalidPath1556--- PASS: TestReadProxyConditionalGet (0.34s)1557=== CONT TestReadProxyOutlastsServerWriteTimeout15582026/10/06 10:42:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35157/oidc1559--- PASS: TestService_ReadScope_PublicByDefault (0.33s)1560=== CONT TestObjectStatsTrigger15612026/10/06 10:42:49 INFO Starting HTTP server address=127.0.0.1:3549115622026/10/06 10:42:49 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1390110766/001/proxy.sock15632026/10/06 10:42:49 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15642026/10/06 10:42:49 INFO Shutdown signal received, draining in-flight requests timeout=10s1565--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.36s)1566=== CONT TestOrphanedObjectsGC1567=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1568=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1569=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1570=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1571=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1572=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1573=== CONT TestReadProxyNarinfoAlreadyDecompressed1574--- PASS: TestGCBugBareHashReferences (0.50s)1575=== CONT TestReadProxyNarStreaming15762026/10/06 10:42:49 INFO Received cleanup request method=DELETE path=/api/pending_closures15772026/10/06 10:42:49 INFO Aborted multipart uploads count=0 kept=015782026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures15792026/10/06 10:42:49 INFO Received cleanup request method=DELETE path=/api/pending_closures15802026/10/06 10:42:49 INFO Aborted multipart uploads count=1 kept=015812026/10/06 10:42:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15822026-10-06 10:42:49.081 UTC [1620] ERROR: Closure does not exist: id=115832026-10-06 10:42:49.081 UTC [1620] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE15842026-10-06 10:42:49.081 UTC [1620] STATEMENT: -- name: CommitPendingClosure :exec1585 SELECT commit_pending_closure($1::bigint)1586 1587--- PASS: TestService_cleanupPendingClosuresHandler (0.29s)1588=== CONT TestPendingClosureWriteTimeout1589=== RUN TestPendingClosureWriteTimeout/empty1590=== PAUSE TestPendingClosureWriteTimeout/empty1591=== RUN TestPendingClosureWriteTimeout/400_objects1592=== PAUSE TestPendingClosureWriteTimeout/400_objects1593=== RUN TestPendingClosureWriteTimeout/670k_objects1594=== PAUSE TestPendingClosureWriteTimeout/670k_objects1595=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1596=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1597=== CONT TestReadProxyContentNegotiation15982026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures1599--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.29s)1600=== CONT TestGCEndsOnShutdown/before_the_run16012026/10/06 10:42:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16022026/10/06 10:42:49 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1603--- PASS: TestCompleteMultipartUnregistered (0.26s)1604=== CONT TestProxyWriteTimeout/narinfo1605=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16062026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures1607--- PASS: TestReadProxy404 (0.28s)1608=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16092026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures16102026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures16112026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures1612--- PASS: TestReadProxyHead (0.29s)1613=== CONT TestProxyWriteTimeout/10_GiB_nar1614=== CONT TestProxyWriteTimeout/unknown_size1615=== CONT TestProxyWriteTimeout/1_GiB_nar1616=== CONT TestServerTLSConfig/no_client_CA1617=== CONT TestServerTLSConfig/not_a_PEM_file1618--- PASS: TestProxyWriteTimeout (0.01s)1619 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1620 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1621 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1622 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1623=== CONT TestServerTLSConfig/missing_CA_file1624=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1625--- PASS: TestServerTLSConfig (0.01s)1626 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1627 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1628 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1629--- PASS: TestReadProxyInvalidPath (0.26s)1630=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1631--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.70s)1632=== CONT TestClientErrorHandling/InvalidStorePath16332026/10/06 10:42:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16342026/10/06 10:42:49 WARN Refused reserved pin name=worker-x86_64-linux16352026/10/06 10:42:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16362026/10/06 10:42:49 INFO Received create pin request method=POST path=/api/pins/my-app16372026/10/06 10:42:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1638--- PASS: TestCreatePin_ReservedPins (0.53s)1639=== CONT TestClientErrorHandling/ServerNotAvailable1640--- PASS: TestObjectStatsTrigger (0.32s)1641=== CONT TestClientErrorHandling/InvalidAuthToken1642--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.31s)1643=== CONT TestPush_RejectsBadRequests/no_roots16442026/10/06 10:42:49 INFO Received push request method=POST path=/api/pushes1645=== CONT TestPush_RejectsBadRequests/bad_root16462026/10/06 10:42:49 INFO Received push request method=POST path=/api/pushes1647=== CONT TestPush_RejectsBadRequests/root_not_in_objects16482026/10/06 10:42:49 INFO Received push request method=POST path=/api/pushes1649=== CONT TestPush_RejectsBadRequests/no_objects16502026/10/06 10:42:49 INFO Received push request method=POST path=/api/pushes1651=== CONT TestCacheConfigHandler/full_config,_no_issuer1652--- PASS: TestPush_RejectsBadRequests (0.44s)1653 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1654 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1655 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1656 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1657=== CONT TestCacheConfigHandler/no_signing_keys1658=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1659=== CONT TestCacheConfigHandler/no_cache_url_configured1660--- PASS: TestCacheConfigHandler (0.00s)1661 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1662 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1663 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1664 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1665=== CONT TestResolveDBConnectionString/flag_wins1666=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1667=== CONT TestResolveDBConnectionString/nothing_configured1668=== CONT TestResolveDBConnectionString/missing_file_is_an_error1669=== CONT TestResolveDBConnectionString/file_when_flag_empty1670=== CONT TestParseSingleRange/none1671=== CONT TestParseSingleRange/start_past_EOF1672=== CONT TestParseSingleRange/single_byte1673=== CONT TestParseSingleRange/suffix_exceeds_size1674=== CONT TestParseSingleRange/suffix1675=== CONT TestParseSingleRange/end_clamped_to_size1676=== CONT TestParseSingleRange/open-ended1677=== CONT TestParseSingleRange/closed1678=== CONT TestParseSingleRange/start_far_past_EOF1679=== CONT TestParseSingleRange/malformed_end_before_start1680=== CONT TestParseSingleRange/malformed_both_empty1681=== CONT TestParseSingleRange/malformed_no_dash1682=== CONT TestParseSingleRange/multi-range_ignored1683=== CONT TestParseSingleRange/unknown_unit1684--- PASS: TestResolveDBConnectionString (0.00s)1685 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1686 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1687 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1688 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1689 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1690--- PASS: TestParseSingleRange (0.00s)1691 --- PASS: TestParseSingleRange/none (0.00s)1692 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1693 --- PASS: TestParseSingleRange/single_byte (0.00s)1694 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1695 --- PASS: TestParseSingleRange/suffix (0.00s)1696 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1697 --- PASS: TestParseSingleRange/open-ended (0.00s)1698 --- PASS: TestParseSingleRange/closed (0.00s)1699 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1700 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1701 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1702 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1703 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1704 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1705=== CONT TestIsValidCachePath/narinfo1706=== CONT TestIsValidCachePath/empty1707=== CONT TestIsValidCachePath/random_path1708=== CONT TestIsValidCachePath/short_hash1709=== CONT TestIsValidCachePath/wrong_extension1710=== CONT TestIsValidCachePath/invalid_char_u1711=== CONT TestIsValidCachePath/invalid_char_e1712=== CONT TestIsValidCachePath/leading_slash1713=== CONT TestIsValidCachePath/traversal_in_middle1714=== CONT TestIsValidCachePath/traversal_parent1715=== CONT TestIsValidCachePath/index.html1716=== CONT TestIsValidCachePath/nix-cache-info1717=== CONT TestIsValidCachePath/realisation1718=== CONT TestIsValidCachePath/nar_xz1719=== CONT TestIsValidCachePath/nar_bz21720=== CONT TestIsValidCachePath/nar_zst1721=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1722=== CONT TestIsValidCachePath/log1723=== CONT TestIsValidCachePath/ls1724=== CONT TestIsValidCachePath/nar_uncompressed1725--- PASS: TestIsValidCachePath (0.00s)1726 --- PASS: TestIsValidCachePath/narinfo (0.00s)1727 --- PASS: TestIsValidCachePath/empty (0.00s)1728 --- PASS: TestIsValidCachePath/random_path (0.00s)1729 --- PASS: TestIsValidCachePath/short_hash (0.00s)1730 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1731 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1732 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1733 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1734 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1735 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1736 --- PASS: TestIsValidCachePath/index.html (0.00s)1737 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1738 --- PASS: TestIsValidCachePath/realisation (0.00s)1739 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1740 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1741 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1742 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1743 --- PASS: TestIsValidCachePath/log (0.00s)1744 --- PASS: TestIsValidCachePath/ls (0.00s)1745 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1746=== CONT TestIsValidUploadKey/narinfo1747=== CONT TestIsValidUploadKey/realisation_plus_in_output1748=== CONT TestIsValidUploadKey/unknown_type1749=== CONT TestIsValidUploadKey/empty_key1750=== CONT TestIsValidUploadKey/absolute1751=== CONT TestIsValidUploadKey/traversal_nar1752=== CONT TestIsValidUploadKey/traversal1753=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1754=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1755=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1756=== CONT TestIsValidUploadKey/index.html1757=== CONT TestIsValidUploadKey/nix-cache-info1758=== CONT TestIsValidUploadKey/nar_plain1759=== CONT TestIsValidUploadKey/build_log_home-manager_file1760=== CONT TestIsValidUploadKey/build_log1761=== CONT TestIsValidUploadKey/realisation1762=== CONT TestIsValidUploadKey/listing1763=== CONT TestIsValidUploadKey/build_log_equals1764=== CONT TestIsValidUploadKey/build_log_question_mark1765=== CONT TestIsValidUploadKey/nar_xz1766=== CONT TestIsValidUploadKey/build_log_plus_in_name1767=== CONT TestIsValidUploadKey/nar_zst1768--- PASS: TestIsValidUploadKey (0.00s)1769 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1770 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1771 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1772 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1773 --- PASS: TestIsValidUploadKey/absolute (0.00s)1774 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1775 --- PASS: TestIsValidUploadKey/traversal (0.00s)1776 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1777 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1778 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1779 --- PASS: TestIsValidUploadKey/index.html (0.00s)1780 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1781 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1782 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1783 --- PASS: TestIsValidUploadKey/build_log (0.00s)1784 --- PASS: TestIsValidUploadKey/realisation (0.00s)1785 --- PASS: TestIsValidUploadKey/listing (0.00s)1786 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1787 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1788 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1789 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1790 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1791=== CONT TestService_RequireScope_OIDC/builder_may_write1792=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1793=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1794=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1795=== CONT TestService_RequireScope_OIDC/writer_implies_read1796=== CONT TestService_RequireScope_OIDC/reader_may_read1797=== CONT TestService_RequireScope_OIDC/static_token_may_write1798=== CONT TestService_RequireScope_OIDC/static_token_may_admin1799=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18002026/10/06 10:42:49 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]1801=== CONT TestService_RequireScope_OIDC/reader_may_not_write1802=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1803=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1804=== CONT TestService_RequireScope_OIDC/ops_may_not_write1805=== CONT TestService_RequireScope_OIDC/ops_may_admin1806=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18072026/10/06 10:42:49 INFO Received uploads request method=POST path=/1808=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18092026/10/06 10:42:49 INFO Received complete multipart upload request method=POST path=/1810=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18112026/10/06 10:42:49 INFO Received uploads request method=POST path=/1812=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1813--- PASS: TestService_RequireScope_OIDC (0.35s)1814 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1815 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1816 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1817 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1818 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1819 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1820 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1821 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1823 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1825 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1826 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1827 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)18282026/10/06 10:42:49 INFO Received request for more parts method=POST path=/1829=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1830--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1831 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1832 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1833 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1834 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)18352026/10/06 10:42:49 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/present1836=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18372026/10/06 10:42:49 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]1838=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1839=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18402026/10/06 10:42:49 WARN Authentication failed token_preview=eyJhbGciOi...nz6EWToTaQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1841=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18422026/10/06 10:42:49 INFO Received uploads request method=POST path=/1843--- PASS: TestService_AuthMiddleware_OIDC (0.41s)1844 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1845 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1846 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1847 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1848--- PASS: TestReadProxyNarStreaming (0.32s)1849=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18502026/10/06 10:42:49 INFO Received request for more parts method=POST path=/1851=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18522026/10/06 10:42:49 INFO Received complete multipart upload request method=POST path=/1853=== CONT TestPendingClosureWriteTimeout/empty1854=== CONT TestPendingClosureWriteTimeout/670k_objects1855=== CONT TestPendingClosureWriteTimeout/400_objects1856=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18572026/10/06 10:42:49 INFO Aborted multipart uploads count=0 kept=018582026/10/06 10:42:49 WARN Force mode enabled - objects will be deleted immediately without grace period18592026/10/06 10:42:49 INFO Aborted multipart uploads count=0 kept=018602026/10/06 10:42:49 WARN Force mode enabled - objects will be deleted immediately without grace period18612026/10/06 10:42:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.57643ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18622026-10-06 10:42:49.445 UTC [1725] ERROR: canceling statement due to user request18632026-10-06 10:42:49.445 UTC [1725] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block18642026-10-06 10:42:49.445 UTC [1725] STATEMENT: -- name: MarkStaleObjects :execrows1865 WITH RECURSIVE ct AS (1866 SELECT timezone('UTC', now()) AS now1867 ),1868 closure_reach AS (1869 -- Start with all closure keys1870 SELECT o.key, o.refs1871 FROM objects o1872 INNER JOIN closures c ON o.key = c.key1873 UNION1874 -- Recursively add all referenced objects1875 SELECT o.key, o.refs1876 FROM objects o1877 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1878 ),1879 reachable_objects AS (1880 SELECT DISTINCT key FROM closure_reach1881 ),1882 stale_objects AS (1883 SELECT o.key1884 FROM objects AS o, ct1885 WHERE1886 NOT EXISTS (1887 SELECT 11888 FROM reachable_objects ro1889 WHERE ro.key = o.key1890 )1891 AND NOT EXISTS (1892 SELECT 11893 FROM pending_objects AS po1894 WHERE po.key = o.key1895 )1896 AND o.deleted_at IS NULL -- Only mark fresh objects1897 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1898 FOR UPDATE1899 )1900 UPDATE objects1901 SET1902 deleted_at = ct.now,1903 first_deleted_at = COALESCE(first_deleted_at, ct.now)1904 FROM stale_objects, ct1905 WHERE objects.key = stale_objects.key1906 19072026/10/06 10:42:49 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43905/bucket87/?delete=\": context canceled"19082026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures1909--- PASS: TestGCEndsOnShutdown (0.00s)1910 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)1911 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.29s)1912 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.34s)19132026/10/06 10:42:49 INFO Aborted multipart uploads count=0 kept=019142026/10/06 10:42:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1915--- PASS: TestReadProxyContentNegotiation (0.38s)19162026/10/06 10:42:49 WARN Force mode enabled - objects will be deleted immediately without grace period19172026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures19182026/10/06 10:42:49 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLmVjYjQ5ZGRhLWY4ZTItNGQ3NC1iY2ViLTUwYzVkODc5YzY4OHgxNzkxMjgzMzY5MTUxMTQwMjg2 parts=1019192026/10/06 10:42:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19202026/10/06 10:42:49 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=019212026/10/06 10:42:49 INFO Vacuumed table table=pending_closures19222026/10/06 10:42:49 INFO Completed upload id=119232026/10/06 10:42:49 INFO Vacuumed table table=pending_objects19242026/10/06 10:42:49 INFO Vacuumed table table=multipart_uploads19252026/10/06 10:42:49 INFO Vacuumed table table=closures19262026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures19272026/10/06 10:42:49 INFO Vacuumed table table=objects19282026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures19292026/10/06 10:42:49 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19302026/10/06 10:42:49 WARN Found objects in DB but missing from S3, will re-upload count=119312026/10/06 10:42:49 INFO Aborted multipart uploads count=0 kept=01932--- PASS: TestService_verifyS3Integrity (0.59s)19332026/10/06 10:42:49 WARN Force mode enabled - objects will be deleted immediately without grace period19342026/10/06 10:42:49 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=019352026/10/06 10:42:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19362026/10/06 10:42:49 INFO Vacuumed table table=pending_closures19372026/10/06 10:42:49 INFO Vacuumed table table=pending_objects19382026/10/06 10:42:49 INFO Vacuumed table table=multipart_uploads19392026/10/06 10:42:49 INFO Vacuumed table table=closures19402026/10/06 10:42:49 INFO Vacuumed table table=objects1941--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1942 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)1943 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.29s)19442026/10/06 10:42:49 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTIxZDNkOTAtODQxMS00NTBjLWEzMTktZjU5MDNmZTg3YzdhLjNmMTU3MmIyLTA1YzQtNDIwYi04NmNmLTM1OTlmYjY2NGQ0N3gxNzkxMjgzMzY5MTkwNzQzODk4 parts=1019452026/10/06 10:42:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19462026/10/06 10:42:49 INFO Completed upload id=119472026/10/06 10:42:49 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019482026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures19492026/10/06 10:42:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures1950--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.86s)19512026/10/06 10:42:49 INFO Aborted multipart uploads count=0 kept=019522026/10/06 10:42:49 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=019532026/10/06 10:42:49 INFO Vacuumed table table=pending_closures19542026/10/06 10:42:49 INFO Vacuumed table table=pending_objects19552026/10/06 10:42:49 INFO Vacuumed table table=multipart_uploads19562026/10/06 10:42:49 INFO Vacuumed table table=closures19572026/10/06 10:42:49 INFO Vacuumed table table=objects19582026/10/06 10:42:49 INFO Received uploads request method=POST path=/api/pending_closures19592026/10/06 10:42:49 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001960--- PASS: TestService_createPendingClosureHandler (0.62s)19612026/10/06 10:42:49 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19622026/10/06 10:42:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.810919ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19632026/10/06 10:42:49 INFO lead: released remote=192.0.2.1:12341964--- PASS: TestLeadEndsOnShutdown (1.34s)19652026/10/06 10:42:49 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1966=== NAME TestOrphanedObjectsGC1967 orphaned_objects_gc_test.go:290: GC Test Summary:1968 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1969 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1970 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1971 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1972 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1973--- PASS: TestOrphanedObjectsGC (0.82s)19742026/10/06 10:42:50 INFO lead: released remote=192.0.2.1:123419752026/10/06 10:42:50 INFO lead: acquired remote=192.0.2.1:123419762026/10/06 10:42:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=852.58513ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1977--- 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.92s)1982--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)1983 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1984 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1985 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.02s)1986=== NAME TestOrphanedObjectsGCStressTest1987 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1988 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19892026/10/06 10:42:50 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019902026/10/06 10:42:50 INFO Received create pin request method=POST path=/api/pins/myapp19912026/10/06 10:42:50 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4184188803/001/store/c93pd5dh3sy3vn0p9y18ad6a601rmdfp-pinned-file.txt narinfo_key=c93pd5dh3sy3vn0p9y18ad6a601rmdfp.narinfo19922026/10/06 10:42:50 INFO Starting cleanup of old closures method=DELETE path=/api/closures19932026/10/06 10:42:50 INFO Garbage collection started19942026/10/06 10:42:50 INFO Aborted multipart uploads count=0 kept=019952026/10/06 10:42:50 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/06 10:42:50 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=019972026/10/06 10:42:50 INFO Vacuumed table table=pending_closures19982026/10/06 10:42:50 INFO Vacuumed table table=pending_objects19992026/10/06 10:42:50 INFO Vacuumed table table=multipart_uploads20002026/10/06 10:42:50 INFO Vacuumed table table=closures20012026/10/06 10:42:50 INFO Vacuumed table table=objects20022026/10/06 10:42:50 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02003=== NAME TestClientIntegration2004 client_integration_test.go:323: Objects in database after GC:2005 client_integration_test.go:323: Successfully deleted all objects with GC --force2006--- PASS: TestClientIntegration (2.61s)2007=== NAME TestOrphanedObjectsGCStressTest2008 orphaned_objects_gc_test.go:509: Stress test completed successfully:2009 orphaned_objects_gc_test.go:510: - Active objects preserved: 202010 orphaned_objects_gc_test.go:511: - Objects deleted: 2102011 orphaned_objects_gc_test.go:512: - Total GC'd: 2102012--- PASS: TestOrphanedObjectsGCStressTest (1.99s)20132026/10/06 10:42:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.665564601s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20142026/10/06 10:42:51 INFO lead: released remote=192.0.2.1:12342015--- PASS: TestLeadElectsOneAndHandsOver (2.65s)20162026/10/06 10:42:52 WARN Rate limiter enabled after throttle name=s3-test rate=520172026/10/06 10:42:52 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2018=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2019 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102020 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002021--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.72s)2022=== NAME TestPinProtectsFromGC2023 client_integration_test.go:840: Pin successfully protected closure from garbage collection2024--- PASS: TestPinProtectsFromGC (4.71s)20252026/10/06 10:42:52 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/06 10:42:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.850152ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/06 10:42:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.281214ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 10:42:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=760.000129ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2029--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.50s)2030--- PASS: TestConnectWaitsForAPeerMigration (5.14s)20312026/10/06 10:42:53 INFO Aborted multipart uploads count=1 kept=020322026/10/06 10:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures20332026/10/06 10:42:53 INFO Aborted multipart uploads count=1 kept=02034--- PASS: TestPendingCleanupUsesOneCutoff (6.31s)20352026/10/06 10:42:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.730395468s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20362026/10/06 10:42:55 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"20372026/10/06 10:42:55 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-config20382026/10/06 10:42:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.077541ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20392026/10/06 10:42:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.40098ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20402026/10/06 10:42:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=739.292506ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/06 10:42:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.721163803s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/06 10:42:59 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_closures20432026/10/06 10:42:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.128467ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20442026/10/06 10:42:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.434707ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20452026/10/06 10:42:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=819.522497ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20462026/10/06 10:43:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.552901226s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2047--- PASS: TestClientErrorHandling (0.00s)2048 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)2049 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.53s)2050 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.85s)2051PASS20522026-10-06 10:43:02.356 UTC [128] LOG: received smart shutdown request20532026-10-06 10:43:02.359 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120542026-10-06 10:43:02.370 UTC [133] LOG: shutting down20552026-10-06 10:43:02.371 UTC [133] LOG: checkpoint starting: shutdown immediate20562026-10-06 10:43:03.244 UTC [133] LOG: checkpoint complete: wrote 11029 buffers (67.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.181 s, sync=0.658 s, total=0.874 s; sync files=31336, longest=0.002 s, average=0.001 s; distance=433057 kB, estimate=433057 kB; lsn=0/1BE4E450, redo lsn=0/1BE4E45020572026-10-06 10:43:03.321 UTC [128] LOG: database system is shut down2058Running OIDC tests...2059=== RUN TestAudienceForIssuer2060=== PAUSE TestAudienceForIssuer2061=== RUN TestGlobMatch2062=== PAUSE TestGlobMatch2063=== RUN TestValidateToken_ValidToken2064=== PAUSE TestValidateToken_ValidToken2065=== RUN TestValidateToken_WrongAudience2066=== PAUSE TestValidateToken_WrongAudience2067=== RUN TestValidateToken_Expired2068=== PAUSE TestValidateToken_Expired2069=== RUN TestValidateToken_BoundClaimsMismatch2070=== PAUSE TestValidateToken_BoundClaimsMismatch2071=== RUN TestValidateToken_BoundSubjectMismatch2072=== PAUSE TestValidateToken_BoundSubjectMismatch2073=== RUN TestValidateToken_MultipleProviders2074=== PAUSE TestValidateToken_MultipleProviders2075=== RUN TestValidateToken_NoMatchingProvider2076=== PAUSE TestValidateToken_NoMatchingProvider2077=== RUN TestValidateToken_KubernetesServiceAccount2078=== PAUSE TestValidateToken_KubernetesServiceAccount2079=== RUN TestNewValidator_KubernetesRequiresCA2080=== PAUSE TestNewValidator_KubernetesRequiresCA2081=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2082=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2083=== RUN TestPins_ReservedForMatchingRule2084=== PAUSE TestPins_ReservedForMatchingRule2085=== RUN TestPins_TopLevelShorthand2086=== PAUSE TestPins_TopLevelShorthand2087=== RUN TestPins_ConfigValidation2088=== PAUSE TestPins_ConfigValidation2089=== RUN TestScopes_LegacyProviderDefaultsToWrite2090=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2091=== RUN TestScopes_Rules2092=== PAUSE TestScopes_Rules2093=== RUN TestScopes_ConfigValidation2094=== PAUSE TestScopes_ConfigValidation2095=== CONT TestAudienceForIssuer2096=== CONT TestValidateToken_BoundClaimsMismatch2097--- PASS: TestAudienceForIssuer (0.00s)2098=== CONT TestValidateToken_Expired2099=== CONT TestValidateToken_KubernetesServiceAccount2100=== CONT TestValidateToken_MultipleProviders2101=== CONT TestValidateToken_ValidToken2102=== CONT TestGlobMatch2103=== RUN TestGlobMatch/foo_foo2104=== PAUSE TestGlobMatch/foo_foo2105=== RUN TestGlobMatch/foo_bar2106=== PAUSE TestGlobMatch/foo_bar2107=== RUN TestGlobMatch/*_2108=== PAUSE TestGlobMatch/*_2109=== RUN TestGlobMatch/*_anything2110=== PAUSE TestGlobMatch/*_anything2111=== RUN TestGlobMatch/foo*_foo2112=== PAUSE TestGlobMatch/foo*_foo2113=== RUN TestGlobMatch/foo*_foobar2114=== PAUSE TestGlobMatch/foo*_foobar2115=== RUN TestGlobMatch/foo*_bar2116=== PAUSE TestGlobMatch/foo*_bar2117=== RUN TestGlobMatch/*bar_bar2118=== PAUSE TestGlobMatch/*bar_bar2119=== RUN TestGlobMatch/*bar_foobar2120=== PAUSE TestGlobMatch/*bar_foobar2121=== RUN TestGlobMatch/*bar_foo2122=== PAUSE TestGlobMatch/*bar_foo2123=== RUN TestGlobMatch/foo*bar_foobar2124=== PAUSE TestGlobMatch/foo*bar_foobar2125=== RUN TestGlobMatch/foo*bar_foo123bar2126=== PAUSE TestGlobMatch/foo*bar_foo123bar2127=== RUN TestGlobMatch/foo*bar_foobarbaz2128=== PAUSE TestGlobMatch/foo*bar_foobarbaz2129=== RUN TestGlobMatch/*/*_foo/bar2130=== PAUSE TestGlobMatch/*/*_foo/bar2131=== RUN TestGlobMatch/*/*_foo2132=== PAUSE TestGlobMatch/*/*_foo2133=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2134=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2135=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02136=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02137=== RUN TestGlobMatch/refs/*/main_refs/heads/main2138=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2139=== RUN TestGlobMatch/fo?_foo2140=== PAUSE TestGlobMatch/fo?_foo2141=== RUN TestGlobMatch/fo?_fo2142=== PAUSE TestGlobMatch/fo?_fo2143=== RUN TestGlobMatch/fo?_fooo2144=== CONT TestValidateToken_NoMatchingProvider2145=== 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 TestPins_ConfigValidation2156=== CONT TestGlobMatch/*/*_foo/bar2157=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2158=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2159=== CONT TestGlobMatch/?oo_boo2160=== CONT TestGlobMatch/?oo_foo2161=== CONT TestGlobMatch/fo?_fooo2162=== CONT TestGlobMatch/fo?_fo2163=== CONT TestGlobMatch/fo?_foo2164=== CONT TestGlobMatch/refs/*/main_refs/heads/main2165=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02166=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2167=== CONT TestGlobMatch/*/*_foo2168=== CONT TestGlobMatch/foo*_foo2169=== CONT TestGlobMatch/foo*_bar2170=== CONT TestGlobMatch/foo*_foobar2171=== CONT TestGlobMatch/*_2172=== CONT TestGlobMatch/*_anything2173=== CONT TestGlobMatch/foo_bar2174=== CONT TestGlobMatch/foo*bar_foobar2175=== CONT TestGlobMatch/foo*bar_foobarbaz2176=== CONT TestGlobMatch/foo*bar_foo123bar2177=== CONT TestGlobMatch/*bar_bar2178=== CONT TestGlobMatch/*bar_foo2179=== CONT TestScopes_Rules2180=== CONT TestScopes_LegacyProviderDefaultsToWrite2181=== CONT TestPins_ReservedForMatchingRule2182=== CONT TestPins_TopLevelShorthand2183=== CONT TestValidateToken_BoundSubjectMismatch2184=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2185--- PASS: TestPins_ConfigValidation (0.00s)2186=== CONT TestNewValidator_KubernetesRequiresCA2187=== CONT TestValidateToken_WrongAudience2188=== CONT TestGlobMatch/*bar_foobar2189--- PASS: TestGlobMatch (0.00s)2190 --- PASS: TestGlobMatch/foo_foo (0.00s)2191 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2192 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2193 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2194 --- PASS: TestGlobMatch/?oo_boo (0.00s)2195 --- PASS: TestGlobMatch/?oo_foo (0.00s)2196 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2197 --- PASS: TestGlobMatch/fo?_fo (0.00s)2198 --- PASS: TestGlobMatch/fo?_foo (0.00s)2199 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2200 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2201 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2202 --- PASS: TestGlobMatch/*/*_foo (0.00s)2203 --- PASS: TestGlobMatch/foo*_foo (0.00s)2204 --- PASS: TestGlobMatch/foo*_bar (0.00s)2205 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2206 --- PASS: TestGlobMatch/*_ (0.00s)2207 --- PASS: TestGlobMatch/*_anything (0.00s)2208 --- PASS: TestGlobMatch/foo_bar (0.00s)2209 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2210 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2211 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2212 --- PASS: TestGlobMatch/*bar_bar (0.00s)2213 --- PASS: TestGlobMatch/*bar_foo (0.00s)2214 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2215=== CONT TestScopes_ConfigValidation2216--- PASS: TestScopes_ConfigValidation (0.00s)22172026/10/06 10:43:04 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322182026/10/06 10:43:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43885/oidc22192026/10/06 10:43:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33545/oidc2220--- PASS: TestValidateToken_ValidToken (0.06s)2221--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)2222--- PASS: TestScopes_Rules (0.07s)22232026/10/06 10:43:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36097/oidc2224--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)22252026/10/06 10:43:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39793/oidc22262026/10/06 10:43:04 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:444552227--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)2228--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)22292026/10/06 10:43:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41729/oidc2230--- PASS: TestValidateToken_Expired (0.12s)22312026/10/06 10:43:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41251/oidc2232--- PASS: TestPins_ReservedForMatchingRule (0.12s)22332026/10/06 10:43:05 http: TLS handshake error from 127.0.0.1:57632: remote error: tls: bad certificate2234--- PASS: TestNewValidator_KubernetesRequiresCA (0.18s)22352026/10/06 10:43:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35313/oidc2236--- PASS: TestValidateToken_WrongAudience (0.19s)22372026/10/06 10:43:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39243/oidc22382026/10/06 10:43:05 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34661/oidc2239--- PASS: TestValidateToken_MultipleProviders (0.24s)22402026/10/06 10:43:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44301/oidc2241--- PASS: TestPins_TopLevelShorthand (0.30s)22422026/10/06 10:43:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35679/oidc2243--- PASS: TestValidateToken_BoundClaimsMismatch (0.33s)22442026/10/06 10:43:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33227/oidc2245--- PASS: TestValidateToken_NoMatchingProvider (0.51s)2246PASS2247Running hook tests...2248=== RUN TestSendPathsEmpty2249=== PAUSE TestSendPathsEmpty2250=== RUN TestQueueEnqueueAndFetch2251=== PAUSE TestQueueEnqueueAndFetch2252=== RUN TestQueueDeduplication2253=== PAUSE TestQueueDeduplication2254=== RUN TestQueueRemove2255=== PAUSE TestQueueRemove2256=== RUN TestQueueFetchBatchLimit2257=== PAUSE TestQueueFetchBatchLimit2258=== RUN TestQueueRetryMovesToBack2259=== PAUSE TestQueueRetryMovesToBack2260=== RUN TestQueueFetchRemoveLifecycle2261=== PAUSE TestQueueFetchRemoveLifecycle2262=== RUN TestQueueConcurrentWriters2263=== PAUSE TestQueueConcurrentWriters2264=== RUN TestQueueRemoveLargeClosure2265=== PAUSE TestQueueRemoveLargeClosure2266=== RUN TestServerClientIntegration2267=== PAUSE TestServerClientIntegration2268=== RUN TestServerQueueError2269=== PAUSE TestServerQueueError2270=== RUN TestGetListenerSocketActivation2271 server_test.go:210: === RUN TestGetListenerSocketActivation2272 --- PASS: TestGetListenerSocketActivation (0.00s)2273 PASS2274 2275--- PASS: TestGetListenerSocketActivation (0.01s)2276=== RUN TestDrainIsolatesPoisonPath2277=== PAUSE TestDrainIsolatesPoisonPath2278=== RUN TestRunNotBlockedByPoisonHead2279=== PAUSE TestRunNotBlockedByPoisonHead2280=== RUN TestDrainGivesUpWhenServerDown2281=== PAUSE TestDrainGivesUpWhenServerDown2282=== RUN TestFailedPathPrunedByLaterClosure2283=== PAUSE TestFailedPathPrunedByLaterClosure2284=== RUN TestWorkerUploadsAndRemoves2285=== PAUSE TestWorkerUploadsAndRemoves2286=== RUN TestWorkerSkipsGCdPaths2287=== PAUSE TestWorkerSkipsGCdPaths2288=== RUN TestWorkerPrunesClosureDeps2289=== PAUSE TestWorkerPrunesClosureDeps2290=== RUN TestDrainTimeout2291=== PAUSE TestDrainTimeout2292=== CONT TestSendPathsEmpty2293=== CONT TestRunNotBlockedByPoisonHead2294=== CONT TestQueueFetchRemoveLifecycle2295=== CONT TestQueueRemoveLargeClosure2296=== CONT TestQueueRetryMovesToBack2297=== CONT TestQueueFetchBatchLimit2298=== CONT TestQueueRemove2299=== CONT TestQueueDeduplication2300=== CONT TestQueueEnqueueAndFetch2301=== CONT TestServerClientIntegration2302=== CONT TestDrainIsolatesPoisonPath2303=== CONT TestServerQueueError2304=== CONT TestWorkerSkipsGCdPaths2305=== CONT TestDrainTimeout2306=== CONT TestWorkerPrunesClosureDeps23072026/10/06 10:43:05 ERROR Failed to queue paths error="permission denied" count=12308=== CONT TestQueueConcurrentWriters2309=== CONT TestFailedPathPrunedByLaterClosure2310=== CONT TestWorkerUploadsAndRemoves2311=== CONT TestDrainGivesUpWhenServerDown2312--- PASS: TestSendPathsEmpty (0.00s)2313--- PASS: TestServerClientIntegration (0.00s)2314--- PASS: TestServerQueueError (0.00s)2315--- PASS: TestQueueFetchBatchLimit (0.01s)23162026/10/06 10:43:05 INFO Uploading batch count=223172026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=223182026/10/06 10:43:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1542330514/002/a23192026/10/06 10:43:05 INFO Uploading batch count=423202026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=42321--- PASS: TestQueueEnqueueAndFetch (0.01s)23222026/10/06 10:43:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1542330514/002/b2323--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23242026/10/06 10:43:05 INFO Uploading batch count=223252026/10/06 10:43:05 INFO Upload queue status pending=323262026/10/06 10:43:05 INFO Uploading batch count=123272026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=123282026/10/06 10:43:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3671950084/002/bbb23292026/10/06 10:43:05 INFO Uploading batch count=123302026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=12331--- PASS: TestQueueRetryMovesToBack (0.02s)23322026/10/06 10:43:05 INFO Uploading batch count=123332026/10/06 10:43:05 INFO Uploading batch count=223342026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=223352026/10/06 10:43:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1542330514/002/c23362026/10/06 10:43:05 INFO Upload queue status pending=22337--- PASS: TestQueueRemove (0.02s)23382026/10/06 10:43:05 INFO Uploading batch count=223392026/10/06 10:43:05 INFO Upload queue status pending=223402026/10/06 10:43:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1542330514/002/d23412026/10/06 10:43:05 INFO Upload queue status pending=223422026/10/06 10:43:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3972021562/002/nonexistent23432026/10/06 10:43:05 INFO Uploading batch count=123442026/10/06 10:43:05 INFO Uploading batch count=123452026/10/06 10:43:05 INFO Uploading batch count=123462026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=123472026/10/06 10:43:05 INFO Uploading batch count=123482026/10/06 10:43:05 INFO Uploading batch count=223492026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=223502026/10/06 10:43:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1542330514/002/e2351--- PASS: TestQueueDeduplication (0.02s)23522026/10/06 10:43:05 INFO Uploading batch count=123532026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=123542026/10/06 10:43:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1542330514/002/f23552026/10/06 10:43:05 INFO Uploading batch count=123562026/10/06 10:43:05 ERROR Upload failed error="upload failed" count=123572026/10/06 10:43:05 ERROR Drain finished with paths left in queue remaining=1023582026/10/06 10:43:05 ERROR Drain finished with paths left in queue remaining=12359--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2360--- PASS: TestDrainIsolatesPoisonPath (0.02s)2361--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2362--- PASS: TestWorkerPrunesClosureDeps (0.03s)2363--- PASS: TestWorkerSkipsGCdPaths (0.03s)2364--- PASS: TestWorkerUploadsAndRemoves (0.03s)2365--- PASS: TestQueueRemoveLargeClosure (0.10s)2366--- PASS: TestQueueConcurrentWriters (0.15s)23672026/10/06 10:43:05 ERROR Upload failed error="context deadline exceeded" count=223682026/10/06 10:43:05 ERROR Drain finished with paths left in queue remaining=42369--- PASS: TestDrainTimeout (0.21s)23702026/10/06 10:43:06 INFO Uploading batch count=123712026/10/06 10:43:06 INFO Uploading batch count=123722026/10/06 10:43:06 INFO Uploading batch count=123732026/10/06 10:43:06 ERROR Upload failed error="upload failed" count=123742026/10/06 10:43:06 INFO Uploading batch count=123752026/10/06 10:43:06 ERROR Upload failed error="upload failed" count=123762026/10/06 10:43:06 INFO Uploading batch count=123772026/10/06 10:43:06 ERROR Upload failed error="upload failed" count=123782026/10/06 10:43:06 INFO Uploading batch count=123792026/10/06 10:43:06 ERROR Upload failed error="upload failed" count=123802026/10/06 10:43:06 ERROR Drain finished with paths left in queue remaining=12381--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2382PASS2383Running signing tests...2384=== RUN TestExternalSigner2385=== PAUSE TestExternalSigner2386=== RUN TestExternalSignerWrongPublicKey2387=== PAUSE TestExternalSignerWrongPublicKey2388=== RUN TestExternalSignerErrors2389=== PAUSE TestExternalSignerErrors2390=== RUN TestExternalSignerRestartsAfterCrash2391=== PAUSE TestExternalSignerRestartsAfterCrash2392=== RUN TestExternalSignerProgramErrorKeepsProcess2393=== PAUSE TestExternalSignerProgramErrorKeepsProcess2394=== RUN TestExternalSignerClose2395=== PAUSE TestExternalSignerClose2396=== RUN TestExternalSignerRejectsInvalidPublicKey2397=== PAUSE TestExternalSignerRejectsInvalidPublicKey2398=== RUN TestExternalSignerCancellation2399=== PAUSE TestExternalSignerCancellation2400=== RUN TestGenerateFingerprint2401=== PAUSE TestGenerateFingerprint2402=== RUN TestParseSigningKey2403=== PAUSE TestParseSigningKey2404=== RUN TestSign2405=== PAUSE TestSign2406=== RUN TestSignBatch2407=== PAUSE TestSignBatch2408=== RUN TestNilKeyPublicKey2409=== PAUSE TestNilKeyPublicKey2410=== RUN TestSignErrors2411=== PAUSE TestSignErrors2412=== CONT TestExternalSigner2413=== CONT TestExternalSignerCancellation2414=== CONT TestSignErrors2415=== CONT TestParseSigningKey2416=== RUN TestParseSigningKey/valid_32-byte_key2417=== PAUSE TestParseSigningKey/valid_32-byte_key2418=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2419=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2420=== RUN TestParseSigningKey/no_colon2421=== CONT TestSignBatch2422=== CONT TestExternalSignerRejectsInvalidPublicKey2423=== RUN TestExternalSignerRejectsInvalidPublicKey/#002424=== CONT TestExternalSignerClose2425=== CONT TestExternalSignerProgramErrorKeepsProcess2426=== CONT TestExternalSignerRestartsAfterCrash2427=== CONT TestExternalSignerErrors2428=== CONT TestExternalSignerWrongPublicKey2429=== CONT TestNilKeyPublicKey2430--- PASS: TestNilKeyPublicKey (0.00s)2431=== CONT TestSign2432=== CONT TestGenerateFingerprint2433=== RUN TestGenerateFingerprint/basic_with_references2434=== PAUSE TestParseSigningKey/no_colon2435=== RUN TestParseSigningKey/empty_name2436=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002437=== RUN TestExternalSignerErrors/wrong_signature_length2438=== PAUSE TestParseSigningKey/empty_name2439=== RUN TestParseSigningKey/invalid_base642440=== PAUSE TestParseSigningKey/invalid_base642441=== RUN TestParseSigningKey/wrong_length2442=== PAUSE TestParseSigningKey/wrong_length2443=== PAUSE TestExternalSignerErrors/wrong_signature_length2444=== NAME TestExternalSignerRestartsAfterCrash2445 external_test.go:207: starting signing program: fork/exec /build/TestExternalSignerRestartsAfterCrash800512923/001/sign program: text file busy2446=== PAUSE TestGenerateFingerprint/basic_with_references2447=== RUN TestGenerateFingerprint/no_references2448=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2449=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2450=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2451=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2452=== CONT TestParseSigningKey/valid_32-byte_key2453=== CONT TestParseSigningKey/wrong_length2454=== CONT TestParseSigningKey/invalid_base642455=== CONT TestParseSigningKey/empty_name2456=== CONT TestParseSigningKey/no_colon2457--- FAIL: TestExternalSignerRestartsAfterCrash (0.00s)2458=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2459=== RUN TestExternalSignerErrors/wrong_shape2460=== PAUSE TestExternalSignerErrors/wrong_shape2461=== PAUSE TestGenerateFingerprint/no_references2462=== RUN TestExternalSignerErrors/too_few_signatures2463=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2464=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2465=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2466=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2467=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2468=== CONT TestExternalSignerRejectsInvalidPublicKey/#002469=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2470=== PAUSE TestExternalSignerErrors/too_few_signatures2471=== RUN TestExternalSignerErrors/wrong_signature_name2472=== PAUSE TestExternalSignerErrors/wrong_signature_name2473=== RUN TestExternalSignerErrors/program_error2474=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2475=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2476=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2477=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2478=== RUN TestGenerateFingerprint/invalid_nar_hash_length2479=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2480=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2481=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2482=== PAUSE TestExternalSignerErrors/program_error2483=== RUN TestExternalSignerErrors/invalid_JSON2484=== PAUSE TestExternalSignerErrors/invalid_JSON2485=== RUN TestExternalSignerErrors/wrong_signatures_shape2486=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2487=== RUN TestExternalSignerErrors/unrequested_key2488=== PAUSE TestExternalSignerErrors/unrequested_key2489=== RUN TestExternalSignerErrors/exit_at_startup2490=== RUN TestSignErrors/nil_key2491=== PAUSE TestSignErrors/nil_key2492=== RUN TestSignErrors/nil_narinfo2493=== PAUSE TestSignErrors/nil_narinfo2494=== RUN TestGenerateFingerprint/invalid_store_path_prefix2495=== RUN TestSignErrors/invalid_narinfo2496=== PAUSE TestSignErrors/invalid_narinfo2497=== RUN TestSignErrors/canceled2498=== PAUSE TestSignErrors/canceled2499=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2500--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2501 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2502 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2503 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2504 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2505 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2506=== PAUSE TestExternalSignerErrors/exit_at_startup2507=== CONT TestSignErrors/nil_key2508=== CONT TestSignErrors/invalid_narinfo2509=== CONT TestSignErrors/nil_narinfo2510=== CONT TestSignErrors/canceled2511=== RUN TestGenerateFingerprint/invalid_reference_prefix2512=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2513=== CONT TestGenerateFingerprint/basic_with_references2514=== CONT TestGenerateFingerprint/invalid_store_path_prefix2515=== CONT TestGenerateFingerprint/invalid_nar_hash_length2516=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2517=== RUN TestExternalSignerErrors/exit_on_request2518--- PASS: TestParseSigningKey (0.00s)2519 --- PASS: TestParseSigningKey/wrong_length (0.00s)2520 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2521 --- PASS: TestParseSigningKey/empty_name (0.00s)2522 --- PASS: TestParseSigningKey/no_colon (0.00s)2523 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2524 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2525--- PASS: TestSign (0.00s)2526=== CONT TestGenerateFingerprint/invalid_reference_prefix2527=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2528=== CONT TestGenerateFingerprint/no_references2529=== PAUSE TestExternalSignerErrors/exit_on_request2530--- PASS: TestSignErrors (0.00s)2531 --- PASS: TestSignErrors/nil_key (0.00s)2532 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2533 --- PASS: TestSignErrors/nil_narinfo (0.00s)2534 --- PASS: TestSignErrors/canceled (0.00s)2535=== RUN TestExternalSignerErrors/wrong_id2536=== PAUSE TestExternalSignerErrors/wrong_id2537=== RUN TestExternalSignerErrors/null_signatures2538=== PAUSE TestExternalSignerErrors/null_signatures2539=== RUN TestExternalSignerErrors/invalid_signature_base642540=== PAUSE TestExternalSignerErrors/invalid_signature_base642541=== RUN TestExternalSignerErrors/null2542=== PAUSE TestExternalSignerErrors/null2543--- PASS: TestGenerateFingerprint (0.00s)2544 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2545 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2546 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2547 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2548 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2549 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2550 --- PASS: TestGenerateFingerprint/no_references (0.00s)2551--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2552--- PASS: TestSignBatch (0.00s)2553=== RUN TestExternalSignerErrors/missing_signatures2554=== PAUSE TestExternalSignerErrors/missing_signatures2555=== RUN TestExternalSignerErrors/missing_signature_name2556=== PAUSE TestExternalSignerErrors/missing_signature_name2557=== CONT TestExternalSignerErrors/wrong_signature_length2558=== CONT TestExternalSignerErrors/exit_at_startup2559=== CONT TestExternalSignerErrors/null_signatures2560=== CONT TestExternalSignerErrors/program_error2561=== CONT TestExternalSignerErrors/missing_signature_name2562=== CONT TestExternalSignerErrors/missing_signatures2563=== CONT TestExternalSignerErrors/null2564=== CONT TestExternalSignerErrors/wrong_id2565=== CONT TestExternalSignerErrors/unrequested_key2566=== CONT TestExternalSignerErrors/wrong_signatures_shape2567=== CONT TestExternalSignerErrors/invalid_JSON2568=== CONT TestExternalSignerErrors/exit_on_request2569=== CONT TestExternalSignerErrors/too_few_signatures2570=== CONT TestExternalSignerErrors/wrong_signature_name2571=== CONT TestExternalSignerErrors/wrong_shape2572=== CONT TestExternalSignerErrors/invalid_signature_base642573--- PASS: TestExternalSignerClose (0.00s)2574--- PASS: TestExternalSignerWrongPublicKey (0.00s)2575--- PASS: TestExternalSigner (0.01s)2576--- PASS: TestExternalSignerErrors (0.00s)2577 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2578 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2579 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2580 --- PASS: TestExternalSignerErrors/program_error (0.00s)2581 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2582 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2583 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2584 --- PASS: TestExternalSignerErrors/null (0.00s)2585 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2586 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2587 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2588 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2589 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2590 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2591 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2592 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2593--- PASS: TestExternalSignerCancellation (0.02s)2594FAIL