niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #396
· 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 TestScriptTokenEmptyCommand101--- PASS: TestScriptTokenEmptyCommand (0.00s)102=== CONT TestEncodeNixBase32103=== RUN TestEncodeNixBase32/test_string_hash104=== PAUSE TestEncodeNixBase32/test_string_hash105=== RUN TestEncodeNixBase32/empty_input106=== PAUSE TestEncodeNixBase32/empty_input107=== CONT TestResolveStorePath108=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess109=== CONT TestRateLimiterFeedback1102026/10/07 09:36:03 WARN Rate limiter enabled after throttle name=server-test rate=5111=== CONT TestScriptTokenNoExpiryRerunsEveryCall112=== RUN TestRateLimiterFeedback/429_enables_limiter113=== PAUSE TestRateLimiterFeedback/429_enables_limiter114=== RUN TestRateLimiterFeedback/503_enables_limiter115=== PAUSE TestRateLimiterFeedback/503_enables_limiter116=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter117=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter118=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter119=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter120=== CONT TestPathInfoCACompatibility121=== CONT TestParsePathInfoJSON122=== CONT TestPathInfoHashCompatibility123=== CONT TestGetStorePathHash124=== CONT TestDoWithRetry_BodyReplayedViaGetBody125=== CONT TestConvertHashToNix32126=== CONT TestScriptTokenScriptFails127=== CONT TestEncodeNixBase32WithRealHash128=== CONT TestScriptTokenBadJSON129=== CONT TestUploadMultipart_PartsInParallel130=== CONT TestScriptTokenEmptyToken131=== CONT TestUploadMultipart_SupersededByPeer132=== CONT TestScriptTokenCachesUntilRefresh133=== CONT TestPartSizeForNAR134=== CONT TestStreamPushReportsSignatures135=== CONT TestClientSignaturesByStorePath136=== CONT TestDumpPathWriterError137=== CONT TestStreamPushRequestLine138=== CONT TestParsePathInfoJSONMultiplePaths139--- PASS: TestResolveStorePath (0.00s)140=== CONT TestStreamPushReportsEveryPath141=== CONT TestStreamPushBatchesUnderLoad142=== RUN TestParsePathInfoJSON/Nix_format143=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)144=== RUN TestGetStorePathHash/valid_store_path145=== RUN TestConvertHashToNix32/SRI_format_to_Nix32146=== RUN TestPathInfoCACompatibility/null_ca_field147=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon149=== PAUSE TestGetStorePathHash/valid_store_path150=== RUN TestGetStorePathHash/basename_without_hyphen_should_error151=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error152--- PASS: TestEncodeNixBase32WithRealHash (0.00s)153=== CONT TestFileTokenEmpty154=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error155=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error156=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error157=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error158=== CONT TestShellSplitErrors159--- PASS: TestShellSplitErrors (0.00s)160=== CONT TestStreamPushGivesUpOnDeadServer161=== RUN TestUploadMultipart_SupersededByPeer/exists162=== PAUSE TestUploadMultipart_SupersededByPeer/exists163--- PASS: TestScriptTokenScriptFails (0.00s)164=== CONT TestFileTokenMissing165--- PASS: TestFileTokenEmpty (0.03s)166=== CONT TestShellSplit167--- PASS: TestShellSplit (0.00s)1682026/10/07 09:36:03 ERROR Upload failed error=boom count=1169=== CONT TestFileTokenReadsAndCaches170--- PASS: TestStreamPushReportsEveryPath (0.00s)1712026/10/07 09:36:03 WARN Rate limiter enabled after throttle name=server-test rate=5172--- PASS: TestClientSignaturesByStorePath (0.00s)173=== CONT TestStreamPushIsolatesFailures1742026/10/07 09:36:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45097175--- PASS: TestDoServerRequestAttachesToken (0.04s)176=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1772026/10/07 09:36:03 ERROR Upload failed error="bad path" count=31782026/10/07 09:36:03 WARN Rate limiter backed off name=server-test rate=51792026/10/07 09:36:03 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45097180=== CONT TestSetClientTLSErrors181=== RUN TestUploadMultipart_SupersededByPeer/missing182=== CONT TestSetClientTLS183=== PAUSE TestUploadMultipart_SupersededByPeer/missing184--- PASS: TestStreamPushIsolatesFailures (0.00s)185--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)1862026/10/07 09:36:03 ERROR Upload failed error="connection refused" count=20187=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1882026/10/07 09:36:03 ERROR Server seems unavailable, giving up on batch untried=17189=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths190=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths191=== PAUSE TestParsePathInfoJSON/Nix_format1922026/10/07 09:36:03 ERROR Upload failed error=boom count=1193=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32194--- PASS: TestStreamPushReportsSignatures (0.00s)195=== RUN TestConvertHashToNix32/already_Nix32_format196=== PAUSE TestConvertHashToNix32/already_Nix32_format197--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)198=== CONT TestDumpPathSingleFile199=== RUN TestConvertHashToNix32/invalid_format200=== RUN TestPartSizeForNAR/zero_stays_at_minimum201=== PAUSE TestConvertHashToNix32/invalid_format202=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica203=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum204=== RUN TestParsePathInfoJSON/Lix_format205=== PAUSE TestParsePathInfoJSON/Lix_format206=== RUN TestParsePathInfoJSON/empty_input207=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths208=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths209=== PAUSE TestPathInfoCACompatibility/null_ca_field210=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon211=== CONT TestCaseHackSuffix212=== CONT TestDumpPathMatchesNix213--- PASS: TestScriptTokenEmptyToken (0.03s)214=== CONT TestFilterOversizedClosures215=== RUN TestFilterOversizedClosures/no_limit_keeps_everything216=== RUN TestPartSizeForNAR/small_stays_at_minimum217=== CONT TestEncodeNixBase32/test_string_hash218=== CONT TestStaticToken219=== PAUSE TestPartSizeForNAR/small_stays_at_minimum2202026/10/07 09:36:03 INFO Garbage collection started221=== PAUSE TestParsePathInfoJSON/empty_input222=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum223=== RUN TestPathInfoCACompatibility/old_string_format_-_text224=== RUN TestParsePathInfoJSON/whitespace_only225=== PAUSE TestParsePathInfoJSON/whitespace_only226=== RUN TestParsePathInfoJSON/invalid_JSON227=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text228--- PASS: TestScriptTokenBadJSON (0.03s)229--- PASS: TestFileTokenReadsAndCaches (0.00s)230=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything231=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== RUN TestFilterOversizedClosures/all_closures_skipped234--- PASS: TestStaticToken (0.00s)235=== PAUSE TestFilterOversizedClosures/all_closures_skipped236=== CONT TestRateLimiterFeedback/429_enables_limiter237=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter238=== CONT TestRegisterUploadedObjectReusesConnections2392026/10/07 09:36:03 INFO Garbage collection started240=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum241=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts242=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts243=== RUN TestPartSizeForNAR/1_TiB244=== PAUSE TestPartSizeForNAR/1_TiB245=== RUN TestPartSizeForNAR/5_TiB_S3_max_object246=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object247=== RUN TestPartSizeForNAR/capped_at_5_GiB248=== PAUSE TestPartSizeForNAR/capped_at_5_GiB249=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI250=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI251=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512252=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512253=== CONT TestRateLimiterFeedback/503_enables_limiter254=== RUN TestSetClientTLSErrors/missing_cert_file255=== PAUSE TestSetClientTLSErrors/missing_cert_file256=== RUN TestSetClientTLSErrors/missing_key_file257=== PAUSE TestSetClientTLSErrors/missing_key_file258=== RUN TestSetClientTLSErrors/missing_ca_file259=== PAUSE TestParsePathInfoJSON/invalid_JSON260=== CONT TestGetStorePathHash/valid_store_path261=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error262=== CONT TestGetStorePathHash/basename_without_hyphen_should_error263=== CONT TestUploadMultipart_SupersededByPeer/exists264=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive265=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error266=== CONT TestConvertHashToNix32/SRI_format_to_Nix32267=== CONT TestConvertHashToNix32/invalid_format268=== CONT TestConvertHashToNix32/already_Nix32_format269=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2702026/10/07 09:36:03 WARN Rate limiter enabled after throttle name=server-test rate=5271=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2722026/10/07 09:36:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:457472732026/10/07 09:36:03 WARN Rate limiter enabled after throttle name=server-test rate=52742026/10/07 09:36:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:330572752026/10/07 09:36:03 WARN Rate limiter backed off name=server-test rate=5276=== CONT TestFilterOversizedClosures/no_limit_keeps_everything277=== CONT TestFilterOversizedClosures/all_closures_skipped2782026/10/07 09:36:03 WARN Rate limiter backed off name=server-test rate=5279=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2802026/10/07 09:36:03 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=2000281=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2822026/10/07 09:36:03 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=50283=== CONT TestPartSizeForNAR/5_TiB_S3_max_object284=== CONT TestPartSizeForNAR/zero_stays_at_minimum285=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum286=== CONT TestPartSizeForNAR/small_stays_at_minimum287=== CONT TestParsePathInfoJSON/Nix_format288=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI289=== RUN TestSetClientTLS/rejects_connection_without_client_cert290=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert291=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512292=== CONT TestParsePathInfoJSON/whitespace_only2932026/10/07 09:36:03 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=0294=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon295=== CONT TestParsePathInfoJSON/invalid_JSON296=== CONT TestParsePathInfoJSON/empty_input297=== CONT TestParsePathInfoJSON/Lix_format298=== CONT TestPartSizeForNAR/1_TiB299=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive300=== RUN TestPathInfoCACompatibility/new_structured_format_-_text301=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text302=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method303=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method304=== CONT TestPathInfoCACompatibility/null_ca_field305=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA306=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA307=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method308=== CONT TestPathInfoCACompatibility/old_string_format_-_text309=== CONT TestPartSizeForNAR/capped_at_5_GiB310=== RUN TestSetClientTLS/preserves_debug_logging_transport311=== PAUSE TestSetClientTLS/preserves_debug_logging_transport312=== CONT TestSetClientTLS/rejects_connection_without_client_cert313=== CONT TestSetClientTLS/preserves_debug_logging_transport314=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA315=== CONT TestPathInfoCACompatibility/new_structured_format_-_text316--- PASS: TestFileTokenMissing (0.00s)317=== PAUSE TestSetClientTLSErrors/missing_ca_file318=== RUN TestSetClientTLSErrors/invalid_ca_file319=== PAUSE TestSetClientTLSErrors/invalid_ca_file320=== CONT TestSetClientTLSErrors/missing_cert_file321=== CONT TestUploadMultipart_SupersededByPeer/missing322=== CONT TestSetClientTLSErrors/invalid_ca_file323=== CONT TestSetClientTLSErrors/missing_key_file324=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts325=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive326=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter327--- PASS: TestGetStorePathHash (0.00s)328 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)329 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)330 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)331 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)332--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)333--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)334=== CONT TestEncodeNixBase32/empty_input335--- PASS: TestEncodeNixBase32 (0.00s)336 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)337 --- PASS: TestEncodeNixBase32/empty_input (0.00s)338=== CONT TestSetClientTLSErrors/missing_ca_file339--- PASS: TestConvertHashToNix32 (0.04s)340 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)341 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)342 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)343--- PASS: TestParsePathInfoJSON (0.04s)344 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)345 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)346 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)347 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)348 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)349--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)350 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)351 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)352--- PASS: TestFilterOversizedClosures (0.00s)353 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)354 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)355 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)356--- PASS: TestPathInfoHashCompatibility (0.04s)357 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)358 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)359 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)360 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)361--- PASS: TestPartSizeForNAR (0.00s)362 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)363 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)365 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)367 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)368 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)369--- PASS: TestPathInfoCACompatibility (0.04s)370 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)371 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)372 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)373 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)374 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)375--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)376 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)377 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)378--- PASS: TestSetClientTLSErrors (0.01s)379 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)380 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)381 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)382 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)383--- PASS: TestRateLimiterFeedback (0.00s)384 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)385 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)387 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)388--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)389--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)3902026/10/07 09:36:03 WARN Garbage collection finished on another replica. Its statistics are not available here391--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)3922026/10/07 09:36:03 http: TLS handshake error from 127.0.0.1:52170: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.00s)394 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestStreamPushRequestLine (0.06s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)399--- PASS: TestDumpPathSingleFile (0.03s)400--- PASS: TestCaseHackSuffix (0.03s)401--- PASS: TestDumpPathWriterError (0.05s)402--- PASS: TestDumpPathMatchesNix (0.08s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)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/postgres3027590484/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/postgres3027590484/data -l logfile start434435/build/postgres3027590484:5432 - no response4362026-10-07 09:36:05.640 UTC [131] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 09:36:05.640 UTC [131] LOG: listening on Unix socket "/build/postgres3027590484/.s.PGSQL.5432"4382026-10-07 09:36:05.645 UTC [138] LOG: database system was shut down at 2026-10-07 09:36:05 UTC4392026-10-07 09:36:05.648 UTC [131] LOG: database system is ready to accept connections440/build/postgres3027590484: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 TestDeleteClosuresRacingPins478=== PAUSE TestDeleteClosuresRacingPins479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/07 09:36:06 INFO lead: acquired remote=192.0.2.1:12344892026/10/07 09:36:06 INFO lead: released remote=192.0.2.1:12344902026/10/07 09:36:06 INFO lead: acquired remote=192.0.2.1:12344912026/10/07 09:36:07 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/07 09:36:07 INFO lead: acquired remote=192.0.2.1:12344992026-10-07 09:36:09.345 UTC [383] FATAL: terminating connection due to administrator command5002026/10/07 09:36:09 INFO lead: acquired remote=192.0.2.1:12345012026/10/07 09:36:10 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/07 09:36:10 INFO lead: released remote=192.0.2.1:12345032026/10/07 09:36:10 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestMetricsCommit574=== PAUSE TestMetricsCommit575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestObjectStatsLargeCommit588=== PAUSE TestObjectStatsLargeCommit589=== RUN TestOrphanedObjectsGC590=== PAUSE TestOrphanedObjectsGC591=== RUN TestOrphanedObjectsGCStressTest592=== PAUSE TestOrphanedObjectsGCStressTest593=== RUN TestCreatePin_ReservedPins594=== PAUSE TestCreatePin_ReservedPins595=== RUN TestPresentReportsOnlyClosureRoots596=== PAUSE TestPresentReportsOnlyClosureRoots597=== RUN TestPresentRefreshesOnlyStaleClosures598=== PAUSE TestPresentRefreshesOnlyStaleClosures599=== RUN TestPresentNotReportedWhileGCDeletesClosure600=== PAUSE TestPresentNotReportedWhileGCDeletesClosure601=== RUN TestParseSingleRange602=== PAUSE TestParseSingleRange603=== RUN TestProxyHeadersOnlyTrustedOnSocket6042026/10/07 09:36:11 INFO Starting HTTP server address=127.0.0.1:341956052026/10/07 09:36:11 INFO Starting HTTP server address=proxy.sock6062026/10/07 09:36:11 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6072026/10/07 09:36:11 INFO Shutdown signal received, draining in-flight requests timeout=10s608--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)609=== RUN TestIsValidCachePath610=== PAUSE TestIsValidCachePath611=== RUN TestReadProxyNarinfo612=== PAUSE TestReadProxyNarinfo613=== RUN TestReadProxyNarinfoAlreadyDecompressed614=== PAUSE TestReadProxyNarinfoAlreadyDecompressed615=== RUN TestReadProxyContentNegotiation616=== PAUSE TestReadProxyContentNegotiation617=== RUN TestReadProxyNarStreaming618=== PAUSE TestReadProxyNarStreaming619=== RUN TestReadProxy404620=== PAUSE TestReadProxy404621=== RUN TestReadProxyInvalidPath622=== PAUSE TestReadProxyInvalidPath623=== RUN TestReadProxyHead624=== PAUSE TestReadProxyHead625=== RUN TestReadProxyOutlastsServerWriteTimeout626=== PAUSE TestReadProxyOutlastsServerWriteTimeout627=== RUN TestReadProxyConditionalGet628=== PAUSE TestReadProxyConditionalGet629=== RUN TestReadProxyRootRedirectsToIndexHTML630=== PAUSE TestReadProxyRootRedirectsToIndexHTML631=== RUN TestReadProxyDisabled632=== PAUSE TestReadProxyDisabled633=== RUN TestReadRedirectNar634=== PAUSE TestReadRedirectNar635=== RUN TestReadRedirectKeepsNarinfoProxied636=== PAUSE TestReadRedirectKeepsNarinfoProxied637=== RUN TestReadProxyRangeRequest638=== PAUSE TestReadProxyRangeRequest639=== RUN TestReadRedirectUsesPublicS3URL640=== PAUSE TestReadRedirectUsesPublicS3URL641=== RUN TestPush_OverlappingRootsStoreOneRowPerKey642=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey643=== RUN TestPush_CompleteCommitsEveryRoot644=== PAUSE TestPush_CompleteCommitsEveryRoot645=== RUN TestPush_RepeatedRootCommitsOnce646=== PAUSE TestPush_RepeatedRootCommitsOnce647=== RUN TestPush_CompleteWaitsForCleanupOfThePush648=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush649=== RUN TestPush_RootsAreLockedInByteOrder650=== PAUSE TestPush_RootsAreLockedInByteOrder651=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit652=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit653=== RUN TestPush_RejectsBadRequests654=== PAUSE TestPush_RejectsBadRequests655=== RUN TestPush_SignsNarinfosOfItsPendingObjects656=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects657=== RUN TestRedundantMultipartUpload658=== PAUSE TestRedundantMultipartUpload659=== RUN TestCompleteMultipartUpload_ErrorButObjectExists660=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists661=== RUN TestCompletedNarNotReofferedAcrossClosures662=== PAUSE TestCompletedNarNotReofferedAcrossClosures663=== RUN TestPresignedUploadRegisteredBeforeCommit664=== PAUSE TestPresignedUploadRegisteredBeforeCommit665=== RUN TestService_Rustfstest666=== PAUSE TestService_Rustfstest667=== RUN TestParseSize668=== PAUSE TestParseSize669=== RUN TestSkippedUploadsHandler670=== PAUSE TestSkippedUploadsHandler671=== RUN TestSystemdListenerNotActivated672--- PASS: TestSystemdListenerNotActivated (0.00s)673=== RUN TestWatchdogBeatsWhenHealthy674--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)675=== RUN TestWatchdogSkipsWhenUnhealthy6762026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 09:36:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"686--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)687=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle688=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle689=== RUN TestProxyWriteTimeout690=== PAUSE TestProxyWriteTimeout691=== RUN TestPendingClosureWriteTimeout692=== PAUSE TestPendingClosureWriteTimeout693=== RUN TestIsValidUploadKey694=== PAUSE TestIsValidUploadKey695=== RUN TestUploadHandlersRejectInvalidKeys696=== PAUSE TestUploadHandlersRejectInvalidKeys697=== RUN TestUploadHandlersRejectOversizedBody698=== PAUSE TestUploadHandlersRejectOversizedBody699=== RUN TestService_cleanupPendingClosuresHandler700=== PAUSE TestService_cleanupPendingClosuresHandler701=== RUN TestService_createPendingClosureHandler702=== PAUSE TestService_createPendingClosureHandler703=== RUN TestService_verifyS3Integrity704=== PAUSE TestService_verifyS3Integrity705=== RUN TestCompleteMultipartUnregistered706=== PAUSE TestCompleteMultipartUnregistered707=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT708=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT709=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle710=== CONT TestService_AuthMiddleware711=== CONT TestSkippedUploadsHandler712=== CONT TestParseSize713--- PASS: TestParseSize (0.00s)714=== CONT TestReadProxyOutlastsServerWriteTimeout715=== CONT TestService_Rustfstest716=== CONT TestPresignedUploadRegisteredBeforeCommit7172026/10/07 09:36:11 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000718=== CONT TestCompletedNarNotReofferedAcrossClosures719=== CONT TestCompleteMultipartUpload_ErrorButObjectExists720=== CONT TestRedundantMultipartUpload721=== CONT TestPush_SignsNarinfosOfItsPendingObjects722=== CONT TestPush_RejectsBadRequests723=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit724=== CONT TestPush_RootsAreLockedInByteOrder725=== CONT TestPush_CompleteWaitsForCleanupOfThePush726=== CONT TestPush_RepeatedRootCommitsOnce727=== CONT TestPush_CompleteCommitsEveryRoot728--- PASS: TestSkippedUploadsHandler (0.00s)729=== CONT TestReadProxyHead730=== CONT TestPush_OverlappingRootsStoreOneRowPerKey731=== CONT TestReadRedirectUsesPublicS3URL732=== CONT TestReadProxyRangeRequest733=== CONT TestReadRedirectKeepsNarinfoProxied734=== CONT TestReadRedirectNar735=== CONT TestReadProxyDisabled736=== CONT TestReadProxyRootRedirectsToIndexHTML737=== CONT TestReadProxyConditionalGet7382026/10/07 09:36:11 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"739--- PASS: TestService_AuthMiddleware (0.26s)740=== CONT TestReadProxyInvalidPath741--- PASS: TestService_Rustfstest (0.29s)742=== CONT TestReadProxy4047432026/10/07 09:36:11 INFO Received uploads request method=POST path=/api/pending_closures7442026/10/07 09:36:11 INFO Received uploads request method=POST path=/api/pending_closures7452026/10/07 09:36:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7462026/10/07 09:36:11 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7472026/10/07 09:36:11 INFO Received uploads request method=POST path=/api/pending_closures7482026/10/07 09:36:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LmVlMGJmNGJiLTcyNTYtNDhjMi1iMmFkLWJlNzA2ZWNkMDY4N3gxNzkxMzY1NzcxNTg3NzA1OTY4749--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.34s)750=== CONT TestReadProxyNarStreaming7512026/10/07 09:36:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LmVlMGJmNGJiLTcyNTYtNDhjMi1iMmFkLWJlNzA2ZWNkMDY4N3gxNzkxMzY1NzcxNTg3NzA1OTY4 parts=1752--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.35s)753=== CONT TestReadProxyContentNegotiation7542026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes755=== RUN TestPush_RejectsBadRequests/no_roots756=== PAUSE TestPush_RejectsBadRequests/no_roots757=== RUN TestPush_RejectsBadRequests/no_objects758=== PAUSE TestPush_RejectsBadRequests/no_objects759=== RUN TestPush_RejectsBadRequests/bad_root760=== PAUSE TestPush_RejectsBadRequests/bad_root761=== RUN TestPush_RejectsBadRequests/root_not_in_objects762=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects763=== CONT TestReadProxyNarinfoAlreadyDecompressed7642026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes7652026/10/07 09:36:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7662026/10/07 09:36:11 INFO Signed narinfos id=1 count=17672026/10/07 09:36:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7682026/10/07 09:36:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7692026/10/07 09:36:11 INFO Received uploads request method=POST path=/api/pending_closures7702026/10/07 09:36:11 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"7712026/10/07 09:36:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7722026/10/07 09:36:11 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"7732026/10/07 09:36:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7742026/10/07 09:36:11 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=17752026/10/07 09:36:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7762026/10/07 09:36:11 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo777--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.41s)778=== CONT TestReadProxyNarinfo7792026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes780--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.45s)781=== CONT TestIsValidCachePath782=== RUN TestIsValidCachePath/narinfo783=== PAUSE TestIsValidCachePath/narinfo784=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars785=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars786=== RUN TestIsValidCachePath/nar_zst787=== PAUSE TestIsValidCachePath/nar_zst788=== RUN TestIsValidCachePath/nar_xz789=== PAUSE TestIsValidCachePath/nar_xz790=== RUN TestIsValidCachePath/nar_bz2791=== PAUSE TestIsValidCachePath/nar_bz2792=== RUN TestIsValidCachePath/nar_uncompressed793=== PAUSE TestIsValidCachePath/nar_uncompressed794=== RUN TestIsValidCachePath/ls795=== PAUSE TestIsValidCachePath/ls796=== RUN TestIsValidCachePath/log797=== PAUSE TestIsValidCachePath/log798=== RUN TestIsValidCachePath/realisation799=== PAUSE TestIsValidCachePath/realisation800=== RUN TestIsValidCachePath/nix-cache-info801=== PAUSE TestIsValidCachePath/nix-cache-info802=== RUN TestIsValidCachePath/index.html803=== PAUSE TestIsValidCachePath/index.html804=== RUN TestIsValidCachePath/traversal_parent805=== PAUSE TestIsValidCachePath/traversal_parent806=== RUN TestIsValidCachePath/traversal_in_middle807=== PAUSE TestIsValidCachePath/traversal_in_middle808=== RUN TestIsValidCachePath/invalid_char_e809=== PAUSE TestIsValidCachePath/invalid_char_e810=== RUN TestIsValidCachePath/invalid_char_u811=== PAUSE TestIsValidCachePath/invalid_char_u812=== RUN TestIsValidCachePath/random_path813=== PAUSE TestIsValidCachePath/random_path814=== RUN TestIsValidCachePath/empty815=== PAUSE TestIsValidCachePath/empty816=== RUN TestIsValidCachePath/leading_slash817=== PAUSE TestIsValidCachePath/leading_slash818=== RUN TestIsValidCachePath/wrong_extension819=== PAUSE TestIsValidCachePath/wrong_extension820=== RUN TestIsValidCachePath/short_hash821=== PAUSE TestIsValidCachePath/short_hash822=== CONT TestParseSingleRange823=== RUN TestParseSingleRange/none824=== PAUSE TestParseSingleRange/none825=== RUN TestParseSingleRange/unknown_unit826=== PAUSE TestParseSingleRange/unknown_unit827=== RUN TestParseSingleRange/multi-range_ignored828=== PAUSE TestParseSingleRange/multi-range_ignored829=== RUN TestParseSingleRange/malformed_no_dash830=== PAUSE TestParseSingleRange/malformed_no_dash831=== RUN TestParseSingleRange/malformed_both_empty832=== PAUSE TestParseSingleRange/malformed_both_empty833=== RUN TestParseSingleRange/malformed_end_before_start834=== PAUSE TestParseSingleRange/malformed_end_before_start835=== RUN TestParseSingleRange/closed836=== PAUSE TestParseSingleRange/closed837=== RUN TestParseSingleRange/open-ended838=== PAUSE TestParseSingleRange/open-ended839=== RUN TestParseSingleRange/end_clamped_to_size840=== PAUSE TestParseSingleRange/end_clamped_to_size841=== RUN TestParseSingleRange/suffix842=== PAUSE TestParseSingleRange/suffix843=== RUN TestParseSingleRange/suffix_exceeds_size844=== PAUSE TestParseSingleRange/suffix_exceeds_size845=== RUN TestParseSingleRange/single_byte846=== PAUSE TestParseSingleRange/single_byte847=== RUN TestParseSingleRange/start_past_EOF848=== PAUSE TestParseSingleRange/start_past_EOF849=== RUN TestParseSingleRange/start_far_past_EOF850=== PAUSE TestParseSingleRange/start_far_past_EOF851=== CONT TestSweepSkipsRowsLockedByPush852--- PASS: TestReadProxyDisabled (0.45s)853=== CONT TestFailedS3DeleteKeepsTombstone854--- PASS: TestReadRedirectNar (0.48s)855=== CONT TestForceGCDuringPushOffersSweptObject856=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows857=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows858=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check859=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check860=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8612026/10/07 09:36:11 INFO Received uploads request method=POST path=/api/pending_closures8622026/10/07 09:36:11 INFO Received uploads request method=POST path=/api/pending_closures8632026/10/07 09:36:11 INFO Received uploads request method=POST path=/api/pending_closures864--- PASS: TestReadProxyHead (0.54s)865=== CONT TestGCSweepDeliversEachKeyOnce8662026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes8672026/10/07 09:36:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8682026/10/07 09:36:11 INFO Received complete push request method=POST path=/api/pushes/1/complete869--- PASS: TestReadRedirectKeepsNarinfoProxied (0.58s)870=== CONT TestTombstonedObjectOfferedWithoutWaiting8712026/10/07 09:36:11 INFO Completed push id=1 objects=6 duration=8.618376ms872--- PASS: TestPush_CompleteCommitsEveryRoot (0.59s)873=== CONT TestGCSweepSkipsPendingObjects874--- PASS: TestReadProxyConditionalGet (0.60s)875=== CONT TestDeduplicatedObjectsRecordedAsPending876--- PASS: TestReadRedirectUsesPublicS3URL (0.63s)877=== CONT TestPushDedupSurvivesConcurrentGC8782026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes8792026/10/07 09:36:11 INFO Received complete push request method=POST path=/api/pushes/1/complete8802026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes8812026/10/07 09:36:11 INFO Completed push id=1 objects=4 duration=10.818775ms8822026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes8832026-10-07 09:36:11.950 UTC [495] ERROR: Push does not exist: id=18842026-10-07 09:36:11.950 UTC [495] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE8852026-10-07 09:36:11.950 UTC [495] STATEMENT: SELECT commit_push($1)886--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.67s)887=== CONT TestGCMetrics8882026/10/07 09:36:11 INFO Received push request method=POST path=/api/pushes8892026-10-07 09:36:11.979 UTC [539] ERROR: could not obtain lock on row in relation "closures"8902026-10-07 09:36:11.979 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8912026/10/07 09:36:11 INFO Received complete push request method=POST path=/api/pushes/1/complete8922026-10-07 09:36:11.980 UTC [539] ERROR: could not obtain lock on row in relation "closures"8932026-10-07 09:36:11.980 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8942026-10-07 09:36:11.980 UTC [539] ERROR: could not obtain lock on row in relation "closures"8952026-10-07 09:36:11.980 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8962026-10-07 09:36:11.981 UTC [539] ERROR: could not obtain lock on row in relation "closures"8972026-10-07 09:36:11.981 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8982026-10-07 09:36:11.981 UTC [539] ERROR: could not obtain lock on row in relation "closures"8992026-10-07 09:36:11.981 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT900--- PASS: TestPush_RootsAreLockedInByteOrder (0.71s)901=== CONT TestGCBugBareHashReferences9022026/10/07 09:36:11 INFO Completed push id=1 objects=4 duration=8.896078ms903--- PASS: TestPush_RepeatedRootCommitsOnce (0.71s)904=== CONT TestGCAdvisoryLockBlocksConcurrentRun905--- PASS: TestReadProxyRangeRequest (0.71s)906=== CONT TestLeadEndsOnShutdown9072026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=0908--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.73s)909=== CONT TestRegisterCompletedObjectNeedsPendingRow9102026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period9112026/10/07 09:36:12 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=09122026/10/07 09:36:12 INFO Vacuumed table table=pending_closures913--- PASS: TestReadProxyInvalidPath (0.49s)914=== CONT TestPresentNotReportedWhileGCDeletesClosure915=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale916=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale917=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh918=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh919=== CONT TestLeadIncumbentAnnouncesAtOnce9202026/10/07 09:36:12 INFO Vacuumed table table=pending_objects9212026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads9222026/10/07 09:36:12 INFO Vacuumed table table=closures9232026/10/07 09:36:12 INFO Vacuumed table table=objects9242026/10/07 09:36:12 INFO Received complete push request method=POST path=/api/pushes/2/complete9252026/10/07 09:36:12 INFO Completed push id=2 objects=4 duration=4.048676ms926--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.77s)927=== CONT TestPresentRefreshesOnlyStaleClosures928--- PASS: TestReadProxy404 (0.51s)929=== CONT TestLeadElectsOneAndHandsOver930--- PASS: TestReadProxyNarStreaming (0.46s)931=== CONT TestPresentReportsOnlyClosureRoots9322026/10/07 09:36:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9332026/10/07 09:36:12 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LmYyZTI4ZWQ0LTFkNmQtNGQzZC05ZmM1LTg1NGQ1MTM1YTQ2ZHgxNzkxMzY1NzcxNjk3OTA3MzYw parts=129342026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures935--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.83s)936=== CONT TestConnectWaitsForAPeerMigration937--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.47s)938=== CONT TestCreatePin_ReservedPins939--- PASS: TestReadProxyContentNegotiation (0.53s)940=== CONT TestResolveDBConnectionString941=== RUN TestResolveDBConnectionString/flag_wins942=== PAUSE TestResolveDBConnectionString/flag_wins943=== RUN TestResolveDBConnectionString/file_when_flag_empty944=== PAUSE TestResolveDBConnectionString/file_when_flag_empty945=== RUN TestResolveDBConnectionString/missing_file_is_an_error946=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error947=== RUN TestResolveDBConnectionString/PGHOST_allows_empty948=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty949=== RUN TestResolveDBConnectionString/nothing_configured950=== PAUSE TestResolveDBConnectionString/nothing_configured951=== CONT TestOrphanedObjectsGCStressTest9522026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/07 09:36:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9542026/10/07 09:36:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LjIxOTRhNWYxLWM0NGYtNGZkZi1iMWJjLTU3NWFiYWQ4MWRmZngxNzkxMzY1NzcxNzk5MTIyODMz parts=129552026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures9562026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures9572026/10/07 09:36:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37549/oidc9582026/10/07 09:36:12 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>959--- PASS: TestReadProxyNarinfo (0.52s)960=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9612026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=09622026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures9632026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period9642026/10/07 09:36:12 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=09652026/10/07 09:36:12 INFO Vacuumed table table=pending_closures9662026/10/07 09:36:12 INFO Vacuumed table table=pending_objects9672026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads9682026/10/07 09:36:12 INFO Vacuumed table table=closures9692026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=09702026/10/07 09:36:12 INFO Vacuumed table table=objects9712026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period9722026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=09732026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period9742026/10/07 09:36:12 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9752026/10/07 09:36:12 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."976--- PASS: TestFailedS3DeleteKeepsTombstone (0.60s)977=== CONT TestOrphanedObjectsGC9782026/10/07 09:36:12 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=09792026/10/07 09:36:12 INFO Vacuumed table table=pending_closures9802026/10/07 09:36:12 INFO Vacuumed table table=pending_objects9812026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads9822026/10/07 09:36:12 INFO Vacuumed table table=closures9832026/10/07 09:36:12 INFO Vacuumed table table=objects984--- PASS: TestSweepSkipsRowsLockedByPush (0.61s)985=== CONT TestDeleteClosuresRacingPins9862026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures9872026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=09882026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period9892026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=09902026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures9912026/10/07 09:36:12 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=09922026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period9932026/10/07 09:36:12 INFO Vacuumed table table=pending_closures9942026/10/07 09:36:12 INFO Vacuumed table table=pending_objects9952026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads9962026/10/07 09:36:12 INFO Vacuumed table table=closures997--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.51s)998=== CONT TestObjectStatsLargeCommit9992026/10/07 09:36:12 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=010002026/10/07 09:36:12 INFO Vacuumed table table=objects1001--- PASS: TestGCSweepDeliversEachKeyOnce (0.56s)1002=== CONT TestClientFallsBackToClosures10032026/10/07 09:36:12 INFO Vacuumed table table=pending_closures10042026/10/07 09:36:12 INFO Vacuumed table table=pending_objects10052026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads10062026/10/07 09:36:12 INFO Vacuumed table table=closures10072026/10/07 09:36:12 INFO Vacuumed table table=objects10082026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures1009--- PASS: TestGCSweepSkipsPendingObjects (0.53s)1010=== CONT TestObjectStatsTrigger1011--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.52s)1012=== CONT TestCacheStatsHandler10132026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures10142026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=010152026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period10162026/10/07 09:36:12 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=010172026/10/07 09:36:12 INFO Vacuumed table table=pending_closures10182026/10/07 09:36:12 INFO Vacuumed table table=pending_objects10192026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads10202026/10/07 09:36:12 INFO Vacuumed table table=closures10212026/10/07 09:36:12 INFO Vacuumed table table=objects1022--- PASS: TestGCMetrics (0.51s)1023=== CONT TestPendingCleanupUsesOneCutoff10242026/10/07 09:36:12 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"1025--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.48s)1026=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10272026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=010282026/10/07 09:36:12 INFO lead: acquired remote=192.0.2.1:123410292026/10/07 09:36:12 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=01030--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.76s)1031=== CONT TestCacheConfigHandler1032=== RUN TestCacheConfigHandler/full_config,_no_issuer1033=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1034=== RUN TestCacheConfigHandler/no_cache_url_configured10352026/10/07 09:36:12 INFO Vacuumed table table=pending_closures1036=== PAUSE TestCacheConfigHandler/no_cache_url_configured1037=== RUN TestCacheConfigHandler/no_signing_keys1038=== PAUSE TestCacheConfigHandler/no_signing_keys1039=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1040=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1041=== CONT TestMultipartCleanup10422026/10/07 09:36:12 INFO Vacuumed table table=pending_objects10432026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads10442026/10/07 09:36:12 INFO Vacuumed table table=closures10452026/10/07 09:36:12 INFO Vacuumed table table=objects10462026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=01047--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.53s)1048=== CONT TestService_ReadScope_PublicByDefault10492026/10/07 09:36:12 WARN Force mode enabled - objects will be deleted immediately without grace period10502026/10/07 09:36:12 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=010512026/10/07 09:36:12 INFO Vacuumed table table=pending_closures10522026/10/07 09:36:12 INFO Vacuumed table table=pending_objects10532026/10/07 09:36:12 INFO Vacuumed table table=multipart_uploads10542026/10/07 09:36:12 INFO Vacuumed table table=closures10552026/10/07 09:36:12 INFO Vacuumed table table=objects1056--- PASS: TestPushDedupSurvivesConcurrentGC (0.63s)1057=== CONT TestServerTLSConfig1058=== RUN TestServerTLSConfig/no_client_CA1059=== PAUSE TestServerTLSConfig/no_client_CA1060=== RUN TestServerTLSConfig/missing_CA_file1061=== PAUSE TestServerTLSConfig/missing_CA_file1062=== RUN TestServerTLSConfig/not_a_PEM_file1063=== PAUSE TestServerTLSConfig/not_a_PEM_file1064=== CONT TestService_NativeMTLS10652026/10/07 09:36:12 INFO lead: acquired remote=192.0.2.1:123410662026/10/07 09:36:12 INFO lead: released remote=192.0.2.1:12341067--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.52s)1068=== CONT TestService_RequireScope_OIDC1069--- PASS: TestPresentRefreshesOnlyStaleClosures (0.55s)1070=== CONT TestClientCADerivations10712026/10/07 09:36:12 INFO lead: acquired remote=192.0.2.1:12341072--- PASS: TestPresentReportsOnlyClosureRoots (0.56s)1073=== CONT TestService_AuthMiddleware_OIDC10742026/10/07 09:36:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10752026/10/07 09:36:12 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LmQwOGY4MTJmLTYzODktNDUwMy04YWQzLWM0OGI1NDIxYzZmMHgxNzkxMzY1NzcyMjA2MTE0MDg2 error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10762026/10/07 09:36:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LjM1NjQxMzJlLTMxODAtNDRiOC1iNjhkLTYzNmRhZjY0NGE1NngxNzkxMzY1NzcyMTk5MzE3MzA2 parts=1210772026/10/07 09:36:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10782026/10/07 09:36:12 INFO Aborted multipart uploads count=1 kept=01079--- PASS: TestRedundantMultipartUpload (1.38s)1080=== CONT TestClientPushesUseOnePush10812026/10/07 09:36:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10822026/10/07 09:36:12 WARN Refused reserved pin name=worker-x86_64-linux10832026/10/07 09:36:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10842026/10/07 09:36:12 INFO Received create pin request method=POST path=/api/pins/my-app10852026/10/07 09:36:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1086--- PASS: TestCreatePin_ReservedPins (0.55s)1087=== CONT TestService_ReadAuthMiddleware1088--- PASS: TestGCBugBareHashReferences (0.72s)1089=== CONT TestMetricsCommit1090--- PASS: TestObjectStatsTrigger (0.39s)1091=== CONT TestPinProtectsFromGC1092--- PASS: TestCacheStatsHandler (0.39s)1093=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10942026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures10952026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures10962026/10/07 09:36:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10972026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures10982026/10/07 09:36:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43385/oidc1099--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.38s)1100=== CONT TestMetricsInventory11012026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures1102--- PASS: TestService_ReadScope_PublicByDefault (0.34s)1103=== CONT TestClientMultipleUploads11042026/10/07 09:36:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11052026/10/07 09:36:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1106--- PASS: TestService_NativeMTLS (0.35s)1107=== CONT TestNARDeduplicationMetadataUploadBug11082026/10/07 09:36:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37147/oidc11092026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures11102026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/07 09:36:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11122026/10/07 09:36:12 INFO Uploading g9ng3v88yv706846778p94m7hxy4scfl-b (216B)11132026/10/07 09:36:12 INFO Uploading pi7rgj1c6w9l16lcv5xzsg115jfkdgfj-shared-dep (136B)11142026/10/07 09:36:12 WARN Failed to register uploaded object key=7bzzxv9ayccbgkxkz278lpiqgkhg4g7h.ls error="server returned 404: 404 page not found\n"11152026/10/07 09:36:12 WARN Failed to register uploaded object key=nar/1q1473rh899xn7psv8hp26vdwrnllzqlcgw8h4m2sdbirpsn6944.nar.zst error="server returned 404: 404 page not found\n"11162026/10/07 09:36:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11172026/10/07 09:36:12 WARN Failed to register uploaded object key=pi7rgj1c6w9l16lcv5xzsg115jfkdgfj.ls error="server returned 404: 404 page not found\n"11182026/10/07 09:36:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11192026/10/07 09:36:12 WARN Failed to register uploaded object key=g9ng3v88yv706846778p94m7hxy4scfl.ls error="server returned 404: 404 page not found\n"11202026/10/07 09:36:12 INFO Signed narinfos id=1 count=211212026/10/07 09:36:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1122--- PASS: TestService_ReadAuthMiddleware (0.29s)11232026/10/07 09:36:12 INFO Signed narinfos id=2 count=21124=== CONT TestClientSharedPathCommittedMidPush11252026/10/07 09:36:12 INFO Uploading 4 narinfos11262026/10/07 09:36:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11272026/10/07 09:36:12 WARN Failed to register uploaded object key=pi7rgj1c6w9l16lcv5xzsg115jfkdgfj.narinfo error="server returned 404: 404 page not found\n"11282026/10/07 09:36:12 WARN Failed to register uploaded object key=7bzzxv9ayccbgkxkz278lpiqgkhg4g7h.narinfo error="server returned 404: 404 page not found\n"11292026/10/07 09:36:12 WARN Failed to register uploaded object key=g9ng3v88yv706846778p94m7hxy4scfl.narinfo error="server returned 404: 404 page not found\n"1130--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.76s)1131=== CONT TestCreatePendingClosureRejectsOversizedNAR11322026/10/07 09:36:12 INFO Received uploads request method=POST path=/api/pending_closures11332026/10/07 09:36:12 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket62/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""1134--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)11352026/10/07 09:36:12 INFO Aborted multipart uploads count=0 kept=11136=== CONT TestClientIntegration11372026/10/07 09:36:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11382026/10/07 09:36:12 WARN Failed to register uploaded object key=pi7rgj1c6w9l16lcv5xzsg115jfkdgfj.narinfo error="server returned 404: 404 page not found\n"11392026/10/07 09:36:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11402026/10/07 09:36:12 INFO Aborted multipart uploads count=1 kept=011412026/10/07 09:36:12 INFO Completed upload id=1 objects=6 duration=11.383881ms11422026/10/07 09:36:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1143--- PASS: TestMultipartCleanup (0.46s)1144=== CONT TestClientWithDependencies11452026/10/07 09:36:12 INFO Completed upload id=2 objects=6 duration=2.324841ms11462026/10/07 09:36:12 INFO Upload complete. (76ms)1147=== NAME TestClientFallsBackToClosures1148 client_pushes_test.go:112: Retrieved narinfo from S3:1149 StorePath: /build/TestClientFallsBackToClosures773821673/001/store/pi7rgj1c6w9l16lcv5xzsg115jfkdgfj-shared-dep1150 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1151 Compression: zstd1152 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821153 NarSize: 1361154 References: 1155 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11562026/10/07 09:36:12 INFO Received push request method=POST path=/api/pushes1157 client_pushes_test.go:112: Retrieved narinfo from S3:1158 StorePath: /build/TestClientFallsBackToClosures773821673/001/store/7bzzxv9ayccbgkxkz278lpiqgkhg4g7h-a1159 URL: nar/1q1473rh899xn7psv8hp26vdwrnllzqlcgw8h4m2sdbirpsn6944.nar.zst1160 Compression: zstd1161 NarHash: sha256:1q1473rh899xn7psv8hp26vdwrnllzqlcgw8h4m2sdbirpsn69441162 NarSize: 2161163 References: /build/TestClientFallsBackToClosures773821673/001/store/pi7rgj1c6w9l16lcv5xzsg115jfkdgfj-shared-dep1164 CA: text:sha256:0kxxhjpwqrnbvsyy49lv5gk3k7yabp9441yn39q1ql9f6lzgw5cb1165 client_pushes_test.go:112: Retrieved narinfo from S3:1166 StorePath: /build/TestClientFallsBackToClosures773821673/001/store/g9ng3v88yv706846778p94m7hxy4scfl-b1167 URL: nar/1q1473rh899xn7psv8hp26vdwrnllzqlcgw8h4m2sdbirpsn6944.nar.zst1168 Compression: zstd1169 NarHash: sha256:1q1473rh899xn7psv8hp26vdwrnllzqlcgw8h4m2sdbirpsn69441170 NarSize: 2161171 References: /build/TestClientFallsBackToClosures773821673/001/store/pi7rgj1c6w9l16lcv5xzsg115jfkdgfj-shared-dep1172 CA: text:sha256:0kxxhjpwqrnbvsyy49lv5gk3k7yabp9441yn39q1ql9f6lzgw5cb1173--- PASS: TestClientFallsBackToClosures (0.62s)1174=== CONT TestCacheConfigHandlerMaxNarSize1175--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1176=== CONT TestGenerateLandingPage1177--- PASS: TestGenerateLandingPage (0.00s)1178=== CONT TestGCTaskStore_GetEmpty1179--- PASS: TestGCTaskStore_GetEmpty (0.00s)1180=== CONT TestGCTaskStore_ConflictDifferentParams1181--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1182=== CONT TestClientErrorHandling1183=== RUN TestClientErrorHandling/InvalidStorePath1184=== PAUSE TestClientErrorHandling/InvalidStorePath1185=== RUN TestClientErrorHandling/InvalidAuthToken1186=== PAUSE TestClientErrorHandling/InvalidAuthToken1187=== RUN TestClientErrorHandling/ServerNotAvailable1188=== PAUSE TestClientErrorHandling/ServerNotAvailable1189=== CONT TestGCTaskStore_DeduplicateSameParams1190--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1191=== CONT TestService_readinessHandler11922026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete1193=== NAME TestClientCADerivations1194 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2228817336/001/store/ylcvcg35dj3wx74ryzrlr2115by8wndl-ca-test11952026/10/07 09:36:13 INFO Completed push id=1 objects=4 duration=9.363462ms11962026/10/07 09:36:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11972026/10/07 09:36:13 INFO Completed upload id=2 objects=2 duration=1.386133ms1198--- PASS: TestMetricsCommit (0.31s)1199=== CONT TestGCTaskStore_StartNew1200--- PASS: TestGCTaskStore_StartNew (0.00s)1201=== CONT TestService_healthCheckHandler1202=== NAME TestOrphanedObjectsGC1203 orphaned_objects_gc_test.go:287: GC Test Summary:1204 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1205 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1206 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1207 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1208 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1209--- PASS: TestOrphanedObjectsGC (0.69s)1210=== CONT TestService_AuthMiddleware_MTLSProxyHeader12112026/10/07 09:36:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12122026/10/07 09:36:13 WARN mTLS auth: bound subjects configured but subject DN unavailable12132026/10/07 09:36:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1214--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.24s)1215=== CONT TestGCEndsOnShutdown1216=== RUN TestGCEndsOnShutdown/before_the_run1217=== PAUSE TestGCEndsOnShutdown/before_the_run1218=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1219=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1220=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1221=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1222=== CONT TestService_cleanupPendingClosuresHandler1223=== NAME TestClientCADerivations1224 client_ca_test.go:139: Found 1 dependencies (including self)1225=== RUN TestService_RequireScope_OIDC/builder_may_write1226=== PAUSE TestService_RequireScope_OIDC/builder_may_write1227=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1228=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1229=== RUN TestService_RequireScope_OIDC/ops_may_admin1230=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1231=== RUN TestService_RequireScope_OIDC/ops_may_not_write1232=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1233=== RUN TestService_RequireScope_OIDC/reader_may_not_write1234=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1235=== RUN TestService_RequireScope_OIDC/static_token_may_admin1236=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1237=== RUN TestService_RequireScope_OIDC/static_token_may_write1238=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1239=== RUN TestService_RequireScope_OIDC/reader_may_read1240=== PAUSE TestService_RequireScope_OIDC/reader_may_read1241=== RUN TestService_RequireScope_OIDC/writer_implies_read1242=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1243=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1244=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1245=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1246=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1247=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1248=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1249=== NAME TestPinProtectsFromGC1250 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1124733056/001/store/vmqiwidm5psll4zl7jhr7z1wfi0s8qc5-pinned-file.txt1251 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1124733056/001/store/vwycxwvz120pzaw9j6d7m45hv52q22yv-unpinned-file.txt1252=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1253=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1254=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1255=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1256=== CONT TestGracefulShutdownDrainsInflight12572026/10/07 09:36:13 INFO Starting HTTP server address=127.0.0.1:4187512582026/10/07 09:36:13 INFO Shutdown signal received, draining in-flight requests timeout=10s1259--- PASS: TestMetricsInventory (0.25s)1260=== CONT TestCommitRacingPendingCleanupKeepsObjects12612026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes12622026/10/07 09:36:13 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12632026/10/07 09:36:13 INFO Uploading ykkbn15vzsj5wdqf9hjwpl28n1p8vcqa-a (208B)12642026/10/07 09:36:13 INFO Uploading lk9ayx8j3swlq1qad5k1a12da75sjmy6-shared-dep (136B)12652026/10/07 09:36:13 WARN Failed to register uploaded object key=mjzy0sjcm83z8sl8jqpa3ijqwmh9xasd.ls error="server returned 404: 404 page not found\n"12662026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12672026/10/07 09:36:13 WARN Failed to register uploaded object key=lk9ayx8j3swlq1qad5k1a12da75sjmy6.ls error="server returned 404: 404 page not found\n"12682026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/1nwr7bdh3h7kvxzb8nb13n47n0gklp355pppwx7cc46glbg0wlg5.nar.zst error="server returned 404: 404 page not found\n"12692026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12702026/10/07 09:36:13 WARN Failed to register uploaded object key=ykkbn15vzsj5wdqf9hjwpl28n1p8vcqa.ls error="server returned 404: 404 page not found\n"12712026/10/07 09:36:13 INFO Signed narinfos id=1 count=312722026/10/07 09:36:13 INFO Uploading 3 narinfos1273=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1274=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1275=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1276=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1277=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1278=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1279=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1280=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1281=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1282=== NAME TestClientMultipleUploads1283 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads731778752/001/store/9rfb6jpkyrxmcvrpv0ywg33w2jb7hcz1-test-file-0.txt1284--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1285=== CONT TestService_verifyS3Integrity12862026/10/07 09:36:13 WARN Failed to register uploaded object key=ykkbn15vzsj5wdqf9hjwpl28n1p8vcqa.narinfo error="server returned 404: 404 page not found\n"12872026/10/07 09:36:13 WARN Failed to register uploaded object key=mjzy0sjcm83z8sl8jqpa3ijqwmh9xasd.narinfo error="server returned 404: 404 page not found\n"12882026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete12892026/10/07 09:36:13 WARN Failed to register uploaded object key=lk9ayx8j3swlq1qad5k1a12da75sjmy6.narinfo error="server returned 404: 404 page not found\n"12902026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes12912026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes12922026/10/07 09:36:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12932026/10/07 09:36:13 INFO Uploading ylcvcg35dj3wx74ryzrlr2115by8wndl-ca-test (144B)12942026/10/07 09:36:13 INFO Completed push id=1 objects=8 duration=6.008793ms12952026/10/07 09:36:13 INFO Upload complete. (62ms)12962026/10/07 09:36:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12972026/10/07 09:36:13 INFO Uploading vmqiwidm5psll4zl7jhr7z1wfi0s8qc5-pinned-file.txt (128B)1298=== NAME TestClientPushesUseOnePush1299 client_pushes_test.go:97: Retrieved narinfo from S3:1300 StorePath: /build/TestClientPushesUseOnePush840321900/001/store/lk9ayx8j3swlq1qad5k1a12da75sjmy6-shared-dep1301 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1302 Compression: zstd1303 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821304 NarSize: 1361305 References: 1306 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13072026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13082026/10/07 09:36:13 WARN Failed to register uploaded object key=ylcvcg35dj3wx74ryzrlr2115by8wndl.ls error="server returned 404: 404 page not found\n"13092026/10/07 09:36:13 WARN Failed to register uploaded object key=log/n9b0h55pqmvs8jv8j8cwrqavqmkfb4mn-ca-test.drv error="server returned 404: 404 page not found\n"13102026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13112026/10/07 09:36:13 INFO Signed narinfos id=1 count=113122026/10/07 09:36:13 INFO Uploading 1 narinfos1313 client_pushes_test.go:97: Retrieved narinfo from S3:1314 StorePath: /build/TestClientPushesUseOnePush840321900/001/store/ykkbn15vzsj5wdqf9hjwpl28n1p8vcqa-a1315 URL: nar/1nwr7bdh3h7kvxzb8nb13n47n0gklp355pppwx7cc46glbg0wlg5.nar.zst1316 Compression: zstd1317 NarHash: sha256:1nwr7bdh3h7kvxzb8nb13n47n0gklp355pppwx7cc46glbg0wlg51318 NarSize: 2081319 References: /build/TestClientPushesUseOnePush840321900/001/store/lk9ayx8j3swlq1qad5k1a12da75sjmy6-shared-dep1320 CA: text:sha256:13sk1wrmkflzrggicx52bvd0721yfckh55jqglr54mh3np949sb713212026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13222026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13232026/10/07 09:36:13 WARN Failed to register uploaded object key=vmqiwidm5psll4zl7jhr7z1wfi0s8qc5.ls error="server returned 404: 404 page not found\n"13242026/10/07 09:36:13 INFO Signed narinfos id=1 count=113252026/10/07 09:36:13 INFO Uploading 1 narinfos13262026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete1327 client_pushes_test.go:97: Retrieved narinfo from S3:1328 StorePath: /build/TestClientPushesUseOnePush840321900/001/store/mjzy0sjcm83z8sl8jqpa3ijqwmh9xasd-b1329 URL: nar/1nwr7bdh3h7kvxzb8nb13n47n0gklp355pppwx7cc46glbg0wlg5.nar.zst13302026/10/07 09:36:13 WARN Failed to register uploaded object key=ylcvcg35dj3wx74ryzrlr2115by8wndl.narinfo error="server returned 404: 404 page not found\n"1331 Compression: zstd1332 NarHash: sha256:1nwr7bdh3h7kvxzb8nb13n47n0gklp355pppwx7cc46glbg0wlg51333 NarSize: 2081334 References: /build/TestClientPushesUseOnePush840321900/001/store/lk9ayx8j3swlq1qad5k1a12da75sjmy6-shared-dep1335 CA: text:sha256:13sk1wrmkflzrggicx52bvd0721yfckh55jqglr54mh3np949sb713362026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete13372026/10/07 09:36:13 WARN Failed to register uploaded object key=vmqiwidm5psll4zl7jhr7z1wfi0s8qc5.narinfo error="server returned 404: 404 page not found\n"1338--- PASS: TestClientPushesUseOnePush (0.51s)1339=== CONT TestPushWaitsForSweepHoldingRow1340=== NAME TestNARDeduplicationMetadataUploadBug1341 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug826229917/001/store/88a25akljgmvd5mi60zcz3h0s2vn6vm1-file1.txt13422026/10/07 09:36:13 INFO Completed push id=1 objects=4 duration=12.218087ms13432026/10/07 09:36:13 INFO Completed push id=1 objects=3 duration=10.772955ms13442026/10/07 09:36:13 INFO Upload complete. (100ms)13452026/10/07 09:36:13 INFO Upload complete. (59ms)1346=== NAME TestClientMultipleUploads1347 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads731778752/001/store/q37s0fsi2iv5dpdydn8fj6x2vz75nbxl-test-file-1.txt1348=== NAME TestClientCADerivations1349 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2228817336/001/store/ylcvcg35dj3wx74ryzrlr2115by8wndl-ca-test1350 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1351 Compression: zstd1352 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1353 NarSize: 1441354 References: 1355 Deriver: /build/TestClientCADerivations2228817336/001/store/n9b0h55pqmvs8jv8j8cwrqavqmkfb4mn-ca-test.drv1356 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1357 client_ca_test.go:185: Checking for realisation files in S3...1358 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1359 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1360=== NAME TestClientMultipleUploads1361 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads731778752/001/store/fam57c1hql2da9mwihwmpnpw47a89l64-test-file-2.txt13622026/10/07 09:36:13 WARN readiness check failed error="closed pool"1363--- PASS: TestService_readinessHandler (0.23s)1364=== CONT TestCompleteMultipartUnregistered1365=== NAME TestClientIntegration1366 client_integration_test.go:286: Created store path: /build/TestClientIntegration1304023303/002/store/03f4fg7i41jpk87z5xpj2k7y8danyz7f-test-file.txt13672026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes13682026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes13692026/10/07 09:36:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13702026/10/07 09:36:13 INFO Uploading vwycxwvz120pzaw9j6d7m45hv52q22yv-unpinned-file.txt (128B)13712026/10/07 09:36:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13722026/10/07 09:36:13 INFO Uploading 88a25akljgmvd5mi60zcz3h0s2vn6vm1-file1.txt (160B)13732026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13742026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13752026/10/07 09:36:13 WARN Failed to register uploaded object key=vwycxwvz120pzaw9j6d7m45hv52q22yv.ls error="server returned 404: 404 page not found\n"13762026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13772026/10/07 09:36:13 INFO Signed narinfos id=2 count=113782026/10/07 09:36:13 INFO Uploading 1 narinfos13792026/10/07 09:36:13 WARN Failed to register uploaded object key=88a25akljgmvd5mi60zcz3h0s2vn6vm1.ls error="server returned 404: 404 page not found\n"13802026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13812026/10/07 09:36:13 INFO Signed narinfos id=1 count=113822026/10/07 09:36:13 INFO Uploading 1 narinfos13832026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/2/complete13842026/10/07 09:36:13 WARN Failed to register uploaded object key=vwycxwvz120pzaw9j6d7m45hv52q22yv.narinfo error="server returned 404: 404 page not found\n"13852026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete13862026/10/07 09:36:13 WARN Failed to register uploaded object key=88a25akljgmvd5mi60zcz3h0s2vn6vm1.narinfo error="server returned 404: 404 page not found\n"13872026/10/07 09:36:13 INFO Completed push id=2 objects=3 duration=2.176839ms13882026/10/07 09:36:13 INFO Upload complete. (44ms)1389--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.23s)1390=== CONT TestGCTaskStore_Fail1391--- PASS: TestGCTaskStore_Fail (0.00s)1392=== CONT TestSweepRechecksPendingAfterLocking13932026/10/07 09:36:13 INFO Completed push id=1 objects=3 duration=14.72411ms13942026/10/07 09:36:13 INFO Upload complete. (63ms)1395=== NAME TestNARDeduplicationMetadataUploadBug1396 metadata_upload_test.go:54: Retrieved narinfo from S3:1397 StorePath: /build/TestNARDeduplicationMetadataUploadBug826229917/001/store/88a25akljgmvd5mi60zcz3h0s2vn6vm1-file1.txt1398 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1399 Compression: zstd1400 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1401 NarSize: 1601402 References: 1403 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1404 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1405 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1406 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1407=== NAME TestClientCADerivations1408 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1409 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1410 error: binary cache 's3://bucket65?endpoint=http://localhost:36301®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2228817336/001/store'1411 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11412--- PASS: TestClientCADerivations (0.69s)1413=== CONT TestGCTaskStore_PhaseUpdates1414--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1415=== CONT TestGetExistingObjectsLocksRows1416--- PASS: TestService_healthCheckHandler (0.26s)1417=== CONT TestGCTaskStore_CompletedAllowsNewTask1418--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1419=== CONT TestGCTaskStore_GetReturnsLatest1420--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1421=== CONT TestProxyWriteTimeout1422=== RUN TestProxyWriteTimeout/narinfo1423=== PAUSE TestProxyWriteTimeout/narinfo1424=== RUN TestProxyWriteTimeout/1_GiB_nar1425=== PAUSE TestProxyWriteTimeout/1_GiB_nar1426=== RUN TestProxyWriteTimeout/10_GiB_nar1427=== PAUSE TestProxyWriteTimeout/10_GiB_nar1428=== RUN TestProxyWriteTimeout/unknown_size1429=== PAUSE TestProxyWriteTimeout/unknown_size1430=== CONT TestIsValidUploadKey1431=== RUN TestIsValidUploadKey/narinfo1432=== PAUSE TestIsValidUploadKey/narinfo1433=== RUN TestIsValidUploadKey/nar_zst1434=== PAUSE TestIsValidUploadKey/nar_zst1435=== RUN TestIsValidUploadKey/nar_xz1436=== PAUSE TestIsValidUploadKey/nar_xz1437=== RUN TestIsValidUploadKey/nar_plain1438=== PAUSE TestIsValidUploadKey/nar_plain1439=== RUN TestIsValidUploadKey/listing1440=== PAUSE TestIsValidUploadKey/listing1441=== RUN TestIsValidUploadKey/build_log1442=== PAUSE TestIsValidUploadKey/build_log1443=== RUN TestIsValidUploadKey/build_log_home-manager_file1444=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1445=== RUN TestIsValidUploadKey/build_log_plus_in_name1446=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1447=== RUN TestIsValidUploadKey/build_log_question_mark1448=== PAUSE TestIsValidUploadKey/build_log_question_mark1449=== RUN TestIsValidUploadKey/build_log_equals1450=== PAUSE TestIsValidUploadKey/build_log_equals1451=== RUN TestIsValidUploadKey/realisation1452=== PAUSE TestIsValidUploadKey/realisation1453=== RUN TestIsValidUploadKey/realisation_plus_in_output1454=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1455=== RUN TestIsValidUploadKey/nix-cache-info1456=== PAUSE TestIsValidUploadKey/nix-cache-info1457=== RUN TestIsValidUploadKey/index.html1458=== PAUSE TestIsValidUploadKey/index.html1459=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1460=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1461=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1462=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1463=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1464=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1465=== RUN TestIsValidUploadKey/traversal1466=== PAUSE TestIsValidUploadKey/traversal1467=== RUN TestIsValidUploadKey/traversal_nar1468=== PAUSE TestIsValidUploadKey/traversal_nar1469=== RUN TestIsValidUploadKey/absolute1470=== PAUSE TestIsValidUploadKey/absolute1471=== RUN TestIsValidUploadKey/empty_key1472=== PAUSE TestIsValidUploadKey/empty_key1473=== RUN TestIsValidUploadKey/unknown_type1474=== PAUSE TestIsValidUploadKey/unknown_type1475=== CONT TestUploadHandlersRejectOversizedBody1476=== NAME TestNARDeduplicationMetadataUploadBug1477 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug826229917/001/store/lxv5vgi4vwsrbwlga60fih81aa0abhfh-file2.txt1478=== NAME TestClientWithDependencies1479 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies998662899/001/store/b51c56106vk7z9bs6ncr783qmg1kzzsw-test-script14802026/10/07 09:36:13 INFO Received cleanup request method=DELETE path=/api/pending_closures14812026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes14822026/10/07 09:36:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures14832026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes14842026/10/07 09:36:13 INFO Garbage collection started14852026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=014862026/10/07 09:36:13 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14872026/10/07 09:36:13 INFO Uploading 9rfb6jpkyrxmcvrpv0ywg33w2jb7hcz1-test-file-0.txt (160B)14882026/10/07 09:36:13 INFO Uploading fam57c1hql2da9mwihwmpnpw47a89l64-test-file-2.txt (160B)14892026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures14902026/10/07 09:36:13 INFO Uploading q37s0fsi2iv5dpdydn8fj6x2vz75nbxl-test-file-1.txt (160B)14912026/10/07 09:36:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14922026/10/07 09:36:13 INFO Uploading 03f4fg7i41jpk87z5xpj2k7y8danyz7f-test-file.txt (152B)14932026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14942026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14952026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14962026/10/07 09:36:13 WARN Failed to register uploaded object key=03f4fg7i41jpk87z5xpj2k7y8danyz7f.ls error="server returned 404: 404 page not found\n"14972026/10/07 09:36:13 WARN Failed to register uploaded object key=9rfb6jpkyrxmcvrpv0ywg33w2jb7hcz1.ls error="server returned 404: 404 page not found\n"14982026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14992026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15002026/10/07 09:36:13 WARN Failed to register uploaded object key=fam57c1hql2da9mwihwmpnpw47a89l64.ls error="server returned 404: 404 page not found\n"15012026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15022026/10/07 09:36:13 WARN Failed to register uploaded object key=q37s0fsi2iv5dpdydn8fj6x2vz75nbxl.ls error="server returned 404: 404 page not found\n"15032026/10/07 09:36:13 INFO Signed narinfos id=1 count=315042026/10/07 09:36:13 INFO Uploading 3 narinfos15052026/10/07 09:36:13 INFO Signed narinfos id=1 count=115062026/10/07 09:36:13 INFO Uploading 1 narinfos15072026/10/07 09:36:13 INFO Received cleanup request method=DELETE path=/api/pending_closures15082026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=015092026/10/07 09:36:13 INFO Aborted multipart uploads count=1 kept=015102026/10/07 09:36:13 WARN Failed to register uploaded object key=9rfb6jpkyrxmcvrpv0ywg33w2jb7hcz1.narinfo error="server returned 404: 404 page not found\n"15112026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete15122026/10/07 09:36:13 WARN Failed to register uploaded object key=q37s0fsi2iv5dpdydn8fj6x2vz75nbxl.narinfo error="server returned 404: 404 page not found\n"15132026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete15142026/10/07 09:36:13 WARN Failed to register uploaded object key=03f4fg7i41jpk87z5xpj2k7y8danyz7f.narinfo error="server returned 404: 404 page not found\n"15152026/10/07 09:36:13 WARN Failed to register uploaded object key=fam57c1hql2da9mwihwmpnpw47a89l64.narinfo error="server returned 404: 404 page not found\n"15162026/10/07 09:36:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15172026-10-07 09:36:13.379 UTC [1015] ERROR: Closure does not exist: id=115182026-10-07 09:36:13.379 UTC [1015] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15192026-10-07 09:36:13.379 UTC [1015] STATEMENT: -- name: CommitPendingClosure :one1520 SELECT commit_pending_closure($1::bigint)::bigint1521 1522--- PASS: TestService_cleanupPendingClosuresHandler (0.34s)1523=== CONT TestPendingClosureWriteTimeout1524=== RUN TestPendingClosureWriteTimeout/empty1525=== PAUSE TestPendingClosureWriteTimeout/empty1526=== RUN TestPendingClosureWriteTimeout/400_objects1527=== PAUSE TestPendingClosureWriteTimeout/400_objects1528=== RUN TestPendingClosureWriteTimeout/670k_objects1529=== PAUSE TestPendingClosureWriteTimeout/670k_objects1530=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1531=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1532=== 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_createPendingClosureHandler15422026/10/07 09:36:13 INFO Completed push id=1 objects=3 duration=5.380447ms15432026/10/07 09:36:13 INFO Upload complete. (104ms)15442026/10/07 09:36:13 INFO Completed push id=1 objects=9 duration=6.429417ms15452026/10/07 09:36:13 INFO Upload complete. (128ms)1546=== NAME TestClientMultipleUploads1547 client_integration_test.go:369: Uploaded 3 paths in 163.15278ms15482026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period1549=== NAME TestClientWithDependencies1550 client_integration_test.go:615: Found 1 dependencies (including self)1551--- PASS: TestClientMultipleUploads (0.52s)1552=== CONT TestPush_RejectsBadRequests/no_roots15532026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes1554=== CONT TestPush_RejectsBadRequests/bad_root15552026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes1556=== CONT TestPush_RejectsBadRequests/root_not_in_objects15572026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes1558=== CONT TestPush_RejectsBadRequests/no_objects15592026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes1560=== CONT TestIsValidCachePath/narinfo1561=== CONT TestIsValidCachePath/short_hash1562=== CONT TestIsValidCachePath/wrong_extension1563=== CONT TestIsValidCachePath/leading_slash1564=== CONT TestIsValidCachePath/empty1565=== CONT TestIsValidCachePath/random_path1566=== CONT TestIsValidCachePath/invalid_char_u1567--- PASS: TestPush_RejectsBadRequests (0.38s)1568 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1569 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1570 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1571 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1572=== CONT TestIsValidCachePath/invalid_char_e1573=== CONT TestIsValidCachePath/traversal_in_middle1574=== CONT TestIsValidCachePath/traversal_parent1575=== CONT TestIsValidCachePath/index.html1576=== CONT TestIsValidCachePath/nix-cache-info1577=== CONT TestIsValidCachePath/realisation1578=== CONT TestIsValidCachePath/log1579=== CONT TestIsValidCachePath/ls1580=== CONT TestIsValidCachePath/nar_uncompressed1581=== CONT TestIsValidCachePath/nar_bz21582=== CONT TestIsValidCachePath/nar_xz1583=== CONT TestIsValidCachePath/nar_zst1584=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1585=== CONT TestParseSingleRange/none1586=== CONT TestParseSingleRange/open-ended1587--- PASS: TestIsValidCachePath (0.00s)1588 --- PASS: TestIsValidCachePath/narinfo (0.00s)1589 --- PASS: TestIsValidCachePath/short_hash (0.00s)1590 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1591 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1592 --- PASS: TestIsValidCachePath/empty (0.00s)1593 --- PASS: TestIsValidCachePath/random_path (0.00s)1594 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1595 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1596 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1597 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1598 --- PASS: TestIsValidCachePath/index.html (0.00s)1599 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1600 --- PASS: TestIsValidCachePath/realisation (0.00s)1601 --- PASS: TestIsValidCachePath/log (0.00s)1602 --- PASS: TestIsValidCachePath/ls (0.00s)1603 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1604 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1605 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1606 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1607 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1608=== CONT TestParseSingleRange/start_far_past_EOF1609=== CONT TestParseSingleRange/start_past_EOF1610=== CONT TestParseSingleRange/single_byte1611=== CONT TestParseSingleRange/suffix_exceeds_size1612=== CONT TestParseSingleRange/suffix1613=== CONT TestParseSingleRange/end_clamped_to_size1614=== CONT TestParseSingleRange/malformed_both_empty1615=== CONT TestParseSingleRange/closed1616=== CONT TestParseSingleRange/malformed_end_before_start1617=== CONT TestParseSingleRange/multi-range_ignored1618=== CONT TestParseSingleRange/malformed_no_dash1619=== CONT TestParseSingleRange/unknown_unit1620=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1621--- PASS: TestParseSingleRange (0.00s)1622 --- PASS: TestParseSingleRange/none (0.00s)1623 --- PASS: TestParseSingleRange/open-ended (0.00s)1624 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1625 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1626 --- PASS: TestParseSingleRange/single_byte (0.00s)1627 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1628 --- PASS: TestParseSingleRange/suffix (0.00s)1629 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1630 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1631 --- PASS: TestParseSingleRange/closed (0.00s)1632 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1633 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1634 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1635 --- PASS: TestParseSingleRange/unknown_unit (0.00s)16362026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes16372026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures16382026/10/07 09:36:13 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=016392026/10/07 09:36:13 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16402026/10/07 09:36:13 INFO Uploading jh5b1prhlxfbvsn8rbjw6jwskpd99gj8-shared-dep (136B)16412026/10/07 09:36:13 INFO Uploading syz5k1p867sahg66lm4kxq3qi4a0dl6b-top (224B)16422026/10/07 09:36:13 INFO Vacuumed table table=pending_closures16432026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/1b3dikxffibafirfi78yis62x66kwpfv1xaks31zkzkr409grkjd.nar.zst error="server returned 404: 404 page not found\n"16442026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16452026/10/07 09:36:13 WARN Failed to register uploaded object key=jh5b1prhlxfbvsn8rbjw6jwskpd99gj8.ls error="server returned 404: 404 page not found\n"16462026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16472026/10/07 09:36:13 WARN Failed to register uploaded object key=syz5k1p867sahg66lm4kxq3qi4a0dl6b.ls error="server returned 404: 404 page not found\n"16482026/10/07 09:36:13 INFO Signed narinfos id=1 count=216492026/10/07 09:36:13 INFO Uploading 2 narinfos16502026/10/07 09:36:13 INFO Vacuumed table table=pending_objects16512026/10/07 09:36:13 INFO Vacuumed table table=multipart_uploads16522026/10/07 09:36:13 INFO Vacuumed table table=closures16532026/10/07 09:36:13 WARN Failed to register uploaded object key=syz5k1p867sahg66lm4kxq3qi4a0dl6b.narinfo error="server returned 404: 404 page not found\n"16542026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete16552026/10/07 09:36:13 WARN Failed to register uploaded object key=jh5b1prhlxfbvsn8rbjw6jwskpd99gj8.narinfo error="server returned 404: 404 page not found\n"16562026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes16572026/10/07 09:36:13 INFO All 1 paths already cached16582026/10/07 09:36:13 INFO Vacuumed table table=objects1659=== NAME TestClientIntegration1660 client_integration_test.go:312: Retrieved narinfo from S3:1661 StorePath: /build/TestClientIntegration1304023303/002/store/03f4fg7i41jpk87z5xpj2k7y8danyz7f-test-file.txt1662 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1663 Compression: zstd1664 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11665 NarSize: 1521666 References: 1667 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116682026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=016692026/10/07 09:36:13 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1670 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1671 client_integration_test.go:313: Decompressed .ls content (64 bytes):1672 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1673 client_integration_test.go:316: Testing garbage collection...16742026/10/07 09:36:13 INFO Completed push id=1 objects=6 duration=8.099492ms16752026/10/07 09:36:13 INFO Upload complete. (68ms)16762026/10/07 09:36:13 WARN Failed to register uploaded object key=lxv5vgi4vwsrbwlga60fih81aa0abhfh.ls error="server returned 404: 404 page not found\n"16772026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16782026/10/07 09:36:13 INFO Signed narinfos id=2 count=116792026/10/07 09:36:13 INFO Uploading 1 narinfos1680=== NAME TestClientSharedPathCommittedMidPush1681 client_integration_test.go:680: Retrieved narinfo from S3:1682 StorePath: /build/TestClientSharedPathCommittedMidPush1467772826/001/store/jh5b1prhlxfbvsn8rbjw6jwskpd99gj8-shared-dep16832026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period1684 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1685 Compression: zstd1686 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821687 NarSize: 1361688 References: 1689 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16902026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures1691 client_integration_test.go:680: Retrieved narinfo from S3:1692 StorePath: /build/TestClientSharedPathCommittedMidPush1467772826/001/store/syz5k1p867sahg66lm4kxq3qi4a0dl6b-top1693 URL: nar/1b3dikxffibafirfi78yis62x66kwpfv1xaks31zkzkr409grkjd.nar.zst1694 Compression: zstd1695 NarHash: sha256:1b3dikxffibafirfi78yis62x66kwpfv1xaks31zkzkr409grkjd1696 NarSize: 2241697 References: /build/TestClientSharedPathCommittedMidPush1467772826/001/store/jh5b1prhlxfbvsn8rbjw6jwskpd99gj8-shared-dep1698 CA: text:sha256:02rrh29s8dm552kirs9xkvxx142bld9ppziq67lijf9ifmlr0xm216992026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/2/complete17002026/10/07 09:36:13 WARN Failed to register uploaded object key=lxv5vgi4vwsrbwlga60fih81aa0abhfh.narinfo error="server returned 404: 404 page not found\n"17012026/10/07 09:36:13 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=017022026/10/07 09:36:13 INFO Completed push id=2 objects=3 duration=3.739913ms1703--- PASS: TestClientSharedPathCommittedMidPush (0.47s)17042026/10/07 09:36:13 INFO Upload complete. (46ms)1705=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17062026/10/07 09:36:13 INFO Vacuumed table table=pending_closures1707=== NAME TestNARDeduplicationMetadataUploadBug1708 metadata_upload_test.go:76: Retrieved narinfo from S3:1709 StorePath: /build/TestNARDeduplicationMetadataUploadBug826229917/001/store/lxv5vgi4vwsrbwlga60fih81aa0abhfh-file2.txt1710 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1711 Compression: zstd1712 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1713 NarSize: 1601714 References: 1715 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17162026/10/07 09:36:13 INFO Vacuumed table table=pending_objects17172026/10/07 09:36:13 INFO Vacuumed table table=multipart_uploads1718 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1719 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1720 {"version":1,"root":{"type":"regular","size":44}}17212026/10/07 09:36:13 INFO Vacuumed table table=closures17222026/10/07 09:36:13 INFO Vacuumed table table=objects1723--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.29s)1724=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1725--- PASS: TestNARDeduplicationMetadataUploadBug (0.55s)1726=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1727--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.35s)1728=== CONT TestResolveDBConnectionString/flag_wins1729=== CONT TestResolveDBConnectionString/nothing_configured1730=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1731=== CONT TestResolveDBConnectionString/missing_file_is_an_error1732=== CONT TestResolveDBConnectionString/file_when_flag_empty1733=== CONT TestCacheConfigHandler/full_config,_no_issuer1734=== CONT TestCacheConfigHandler/no_signing_keys1735=== CONT TestCacheConfigHandler/no_cache_url_configured1736=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1737--- PASS: TestResolveDBConnectionString (0.00s)1738 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1739 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1740 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1741 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1742 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1743=== CONT TestServerTLSConfig/no_client_CA1744=== CONT TestServerTLSConfig/missing_CA_file1745--- PASS: TestCacheConfigHandler (0.00s)1746 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1747 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1748 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1749 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1750=== CONT TestServerTLSConfig/not_a_PEM_file1751--- PASS: TestServerTLSConfig (0.00s)1752 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1753 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1754 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1755=== CONT TestClientErrorHandling/InvalidStorePath1756=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1757=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1758=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1759=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1760=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1761=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1762=== CONT TestClientErrorHandling/InvalidAuthToken17632026/10/07 09:36:13 INFO Received push request method=POST path=/api/pushes17642026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures17652026/10/07 09:36:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures17662026/10/07 09:36:13 INFO Garbage collection started17672026/10/07 09:36:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17682026/10/07 09:36:13 INFO Uploading b51c56106vk7z9bs6ncr783qmg1kzzsw-test-script (136B)17692026/10/07 09:36:13 WARN Failed to register uploaded object key=log/v30im85s8l06zwh4di2micvm23gchihw-test-script.drv error="server returned 404: 404 page not found\n"17702026/10/07 09:36:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17712026/10/07 09:36:13 WARN Failed to register uploaded object key=b51c56106vk7z9bs6ncr783qmg1kzzsw.ls error="server returned 404: 404 page not found\n"17722026/10/07 09:36:13 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17732026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=017742026/10/07 09:36:13 INFO Signed narinfos id=1 count=117752026/10/07 09:36:13 INFO Uploading 1 narinfos17762026/10/07 09:36:13 INFO Received complete push request method=POST path=/api/pushes/1/complete17772026/10/07 09:36:13 WARN Failed to register uploaded object key=b51c56106vk7z9bs6ncr783qmg1kzzsw.narinfo error="server returned 404: 404 page not found\n"17782026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period17792026/10/07 09:36:13 INFO Completed push id=1 objects=4 duration=6.7071ms17802026/10/07 09:36:13 INFO Upload complete. (60ms)1781=== NAME TestClientWithDependencies1782 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies998662899/001/store) requires matching store prefix1783--- PASS: TestClientWithDependencies (0.50s)1784=== CONT TestClientErrorHandling/ServerNotAvailable1785--- PASS: TestGetExistingObjectsLocksRows (0.21s)1786=== CONT TestGCEndsOnShutdown/before_the_run17872026/10/07 09:36:13 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=017882026/10/07 09:36:13 INFO Vacuumed table table=pending_closures17892026/10/07 09:36:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17902026/10/07 09:36:13 INFO Vacuumed table table=pending_objects17912026/10/07 09:36:13 INFO Vacuumed table table=multipart_uploads17922026/10/07 09:36:13 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1793--- PASS: TestCompleteMultipartUnregistered (0.26s)1794=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17952026/10/07 09:36:13 INFO Vacuumed table table=closures17962026/10/07 09:36:13 INFO Vacuumed table table=objects17972026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=017982026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period17992026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures18002026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures18012026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures18022026/10/07 09:36:13 INFO lead: released remote=192.0.2.1:12341803--- PASS: TestLeadEndsOnShutdown (1.57s)1804=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18052026/10/07 09:36:13 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/present18062026/10/07 09:36:13 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=018072026/10/07 09:36:13 INFO Vacuumed table table=pending_closures18082026/10/07 09:36:13 INFO Vacuumed table table=pending_objects18092026/10/07 09:36:13 INFO Vacuumed table table=multipart_uploads18102026/10/07 09:36:13 INFO Vacuumed table table=closures18112026/10/07 09:36:13 INFO Vacuumed table table=objects18122026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures1813--- PASS: TestSweepRechecksPendingAfterLocking (0.32s)1814=== CONT TestService_RequireScope_OIDC/builder_may_write1815=== CONT TestService_RequireScope_OIDC/reader_may_read1816=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1817=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18182026/10/07 09:36:13 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]1819=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1820=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1821=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1822=== CONT TestService_RequireScope_OIDC/writer_implies_read1823=== CONT TestService_RequireScope_OIDC/reader_may_not_write1824=== CONT TestService_RequireScope_OIDC/static_token_may_write1825=== CONT TestService_RequireScope_OIDC/static_token_may_admin1826=== CONT TestService_RequireScope_OIDC/ops_may_admin1827=== CONT TestService_RequireScope_OIDC/ops_may_not_write1828=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1829=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1830--- PASS: TestService_RequireScope_OIDC (0.54s)1831 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1842 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1843 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1844 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1845=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18462026/10/07 09:36:13 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]1847=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1848=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18492026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=018502026/10/07 09:36:13 WARN Authentication failed token_preview=eyJhbGciOi...3QVLUspTLA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1851=== CONT TestProxyWriteTimeout/narinfo1852=== CONT TestProxyWriteTimeout/10_GiB_nar1853=== CONT TestProxyWriteTimeout/1_GiB_nar1854=== CONT TestProxyWriteTimeout/unknown_size1855=== CONT TestIsValidUploadKey/narinfo1856=== CONT TestIsValidUploadKey/realisation_plus_in_output1857=== CONT TestIsValidUploadKey/unknown_type1858=== CONT TestIsValidUploadKey/empty_key1859=== CONT TestIsValidUploadKey/absolute1860=== CONT TestIsValidUploadKey/traversal_nar1861=== CONT TestIsValidUploadKey/traversal1862=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1863--- PASS: TestProxyWriteTimeout (0.00s)1864 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1865 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1866 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1867 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1868=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1869--- PASS: TestService_AuthMiddleware_OIDC (0.51s)1870 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1871 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1872 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1873 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1874=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1875=== CONT TestIsValidUploadKey/index.html1876=== CONT TestIsValidUploadKey/nix-cache-info1877=== CONT TestIsValidUploadKey/build_log_home-manager_file1878=== CONT TestIsValidUploadKey/nar_plain1879=== CONT TestIsValidUploadKey/realisation1880=== CONT TestIsValidUploadKey/build_log1881=== CONT TestIsValidUploadKey/build_log_equals1882=== CONT TestIsValidUploadKey/listing1883=== CONT TestIsValidUploadKey/build_log_question_mark1884=== CONT TestIsValidUploadKey/build_log_plus_in_name1885=== CONT TestIsValidUploadKey/nar_zst1886=== CONT TestIsValidUploadKey/nar_xz1887--- PASS: TestIsValidUploadKey (0.00s)1888 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1889 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1890 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1891 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1892 --- PASS: TestIsValidUploadKey/absolute (0.00s)1893 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1894 --- PASS: TestIsValidUploadKey/traversal (0.00s)1895 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1896 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1897 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1898 --- PASS: TestIsValidUploadKey/index.html (0.00s)1899 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1900 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1901 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1902 --- PASS: TestIsValidUploadKey/realisation (0.00s)1903 --- PASS: TestIsValidUploadKey/build_log (0.00s)1904 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1905 --- PASS: TestIsValidUploadKey/listing (0.00s)1906 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1907 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1908 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1909 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1910=== CONT TestPendingClosureWriteTimeout/empty1911=== CONT TestPendingClosureWriteTimeout/670k_objects1912=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline19132026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period19142026/10/07 09:36:13 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=019152026/10/07 09:36:13 INFO Vacuumed table table=pending_closures19162026/10/07 09:36:13 INFO Vacuumed table table=pending_objects19172026/10/07 09:36:13 INFO Vacuumed table table=multipart_uploads19182026/10/07 09:36:13 INFO Vacuumed table table=closures19192026/10/07 09:36:13 INFO Vacuumed table table=objects1920=== CONT TestPendingClosureWriteTimeout/400_objects1921=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19222026/10/07 09:36:13 INFO Received uploads request method=POST path=/1923=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19242026/10/07 09:36:13 INFO Received complete multipart upload request method=POST path=/1925=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19262026/10/07 09:36:13 INFO Received request for more parts method=POST path=/1927=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19282026/10/07 09:36:13 INFO Received uploads request method=POST path=/1929--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1930 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1931 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1932 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1933 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1934=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19352026/10/07 09:36:13 INFO Received request for more parts method=POST path=/19362026/10/07 09:36:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.157442ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19372026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures1938=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19392026/10/07 09:36:13 INFO Received complete multipart upload request method=POST path=/19402026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=019412026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period19422026/10/07 09:36:13 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=019432026/10/07 09:36:13 INFO Vacuumed table table=pending_closures19442026/10/07 09:36:13 INFO Vacuumed table table=pending_objects19452026/10/07 09:36:13 INFO Vacuumed table table=multipart_uploads19462026/10/07 09:36:13 INFO Vacuumed table table=closures19472026/10/07 09:36:13 INFO Vacuumed table table=objects1948--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1949 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.24s)1950 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)1951=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19522026/10/07 09:36:13 INFO Received uploads request method=POST path=/19532026/10/07 09:36:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19542026/10/07 09:36:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LjdlOGM2ZjQ4LTBmOGQtNGRlNy04YmZhLWFmMzhjMWUyYTZkM3gxNzkxMzY1NzczNDEyNjU2ODU1 parts=1019552026/10/07 09:36:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19562026/10/07 09:36:13 INFO Completed upload id=1 objects=2 duration=2.832245ms19572026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures19582026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures19592026/10/07 09:36:13 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19602026/10/07 09:36:13 WARN Found objects in DB but missing from S3, will re-upload count=11961--- PASS: TestService_verifyS3Integrity (0.59s)19622026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=019632026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period19642026/10/07 09:36:13 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36301/bucket98/?delete=\": context canceled"19652026/10/07 09:36:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19662026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=019672026/10/07 09:36:13 WARN Force mode enabled - objects will be deleted immediately without grace period19682026/10/07 09:36:13 INFO lead: released remote=192.0.2.1:123419692026/10/07 09:36:13 INFO lead: acquired remote=192.0.2.1:123419702026/10/07 09:36:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.014258ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1971--- PASS: TestObjectStatsLargeCommit (1.49s)19722026/10/07 09:36:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19732026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures1974--- PASS: TestGCEndsOnShutdown (0.00s)1975 --- PASS: TestGCEndsOnShutdown/before_the_run (0.24s)1976 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.27s)1977 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.31s)19782026/10/07 09:36:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19792026/10/07 09:36:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzFhYTBiMGYtNDIyYy00ZDc5LTk3YTQtNDlkZjYyZmRhYmM2LjljZGE5ODMyLTc5OTMtNDczNS04MjY1LWExZTc4MDRjNDUzZHgxNzkxMzY1NzczNTU3MDMyNDA5 parts=1019802026/10/07 09:36:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19812026/10/07 09:36:13 INFO Completed upload id=1 objects=2 duration=1.791475ms19822026/10/07 09:36:13 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019832026/10/07 09:36:13 INFO Received uploads request method=POST path=/api/pending_closures19842026/10/07 09:36:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures19852026/10/07 09:36:13 INFO Aborted multipart uploads count=0 kept=019862026/10/07 09:36:13 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=01987--- PASS: TestPushWaitsForSweepHoldingRow (0.79s)19882026/10/07 09:36:13 INFO Vacuumed table table=pending_closures19892026/10/07 09:36:13 INFO Vacuumed table table=pending_objects19902026/10/07 09:36:13 INFO Vacuumed table table=multipart_uploads19912026/10/07 09:36:13 INFO Vacuumed table table=closures19922026/10/07 09:36:13 INFO Vacuumed table table=objects19932026/10/07 09:36:13 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001994--- PASS: TestService_createPendingClosureHandler (0.61s)1995--- PASS: TestDeleteClosuresRacingPins (1.68s)1996--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1997 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.68s)1998 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.70s)1999=== NAME TestOrphanedObjectsGCStressTest2000 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2001 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20022026/10/07 09:36:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=815.338272ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2003 orphaned_objects_gc_test.go:503: Stress test completed successfully:2004 orphaned_objects_gc_test.go:504: - Active objects preserved: 202005 orphaned_objects_gc_test.go:505: - Objects deleted: 2102006 orphaned_objects_gc_test.go:506: - Total GC'd: 2102007--- PASS: TestOrphanedObjectsGCStressTest (2.32s)2008--- PASS: TestPendingClosureWriteTimeout (0.00s)2009 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2010 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2011 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2012 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.08s)2013--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2014 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2015 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2016 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.97s)20172026/10/07 09:36:14 INFO lead: released remote=192.0.2.1:12342018--- PASS: TestLeadElectsOneAndHandsOver (2.89s)20192026/10/07 09:36:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.734578077s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20202026/10/07 09:36:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020212026/10/07 09:36:15 INFO Received create pin request method=POST path=/api/pins/myapp20222026/10/07 09:36:15 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1124733056/001/store/vmqiwidm5psll4zl7jhr7z1wfi0s8qc5-pinned-file.txt narinfo_key=vmqiwidm5psll4zl7jhr7z1wfi0s8qc5.narinfo20232026/10/07 09:36:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures20242026/10/07 09:36:15 INFO Garbage collection started20252026/10/07 09:36:15 INFO Aborted multipart uploads count=0 kept=020262026/10/07 09:36:15 WARN Force mode enabled - objects will be deleted immediately without grace period20272026/10/07 09:36:15 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=020282026/10/07 09:36:15 INFO Vacuumed table table=pending_closures20292026/10/07 09:36:15 INFO Vacuumed table table=pending_objects20302026/10/07 09:36:15 INFO Vacuumed table table=multipart_uploads20312026/10/07 09:36:15 INFO Vacuumed table table=closures20322026/10/07 09:36:15 INFO Vacuumed table table=objects20332026/10/07 09:36:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02034=== NAME TestClientIntegration2035 client_integration_test.go:323: Objects in database after GC:2036 client_integration_test.go:323: Successfully deleted all objects with GC --force2037--- PASS: TestClientIntegration (2.49s)20382026/10/07 09:36:15 WARN Rate limiter enabled after throttle name=s3-test rate=520392026/10/07 09:36:15 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2040=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2041 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102042 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002043--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.42s)2044--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.56s)20452026/10/07 09:36:16 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-config20462026/10/07 09:36:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.634567ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20472026/10/07 09:36:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.6462ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2048--- PASS: TestConnectWaitsForAPeerMigration (5.14s)2049=== NAME TestPinProtectsFromGC2050 client_integration_test.go:840: Pin successfully protected closure from garbage collection2051--- PASS: TestPinProtectsFromGC (4.59s)20522026/10/07 09:36:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=754.626241ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20532026/10/07 09:36:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.611044193s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20542026/10/07 09:36:18 INFO Aborted multipart uploads count=1 kept=020552026/10/07 09:36:18 INFO Received cleanup request method=DELETE path=/api/pending_closures20562026/10/07 09:36:18 INFO Aborted multipart uploads count=1 kept=02057--- PASS: TestPendingCleanupUsesOneCutoff (6.38s)20582026/10/07 09:36:19 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"20592026/10/07 09:36:19 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-config20602026/10/07 09:36:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.049709ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20612026/10/07 09:36:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=386.403875ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20622026/10/07 09:36:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=863.748645ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20632026/10/07 09:36:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.460065191s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20642026/10/07 09:36:22 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_closures20652026/10/07 09:36:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.380746ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20662026/10/07 09:36:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.160768ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20672026/10/07 09:36:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=768.929305ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20682026/10/07 09:36:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.45575384s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2069--- PASS: TestClientErrorHandling (0.00s)2070 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)2071 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.41s)2072 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.34s)2073PASS20742026-10-07 09:36:26.068 UTC [131] LOG: received smart shutdown request20752026-10-07 09:36:26.073 UTC [131] LOG: background worker "logical replication launcher" (PID 141) exited with exit code 120762026-10-07 09:36:26.086 UTC [136] LOG: shutting down20772026-10-07 09:36:26.087 UTC [136] LOG: checkpoint starting: shutdown immediate20782026-10-07 09:36:26.591 UTC [136] LOG: checkpoint complete: wrote 10753 buffers (65.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.178 s, sync=0.299 s, total=0.505 s; sync files=34046, longest=0.092 s, average=0.001 s; distance=531542 kB, estimate=531542 kB; lsn=0/21E7B8C8, redo lsn=0/21E7B8C820792026-10-07 09:36:26.667 UTC [131] LOG: database system is shut down2080Running OIDC tests...2081=== RUN TestAudienceForIssuer2082=== PAUSE TestAudienceForIssuer2083=== RUN TestGlobMatch2084=== PAUSE TestGlobMatch2085=== RUN TestValidateToken_ValidToken2086=== PAUSE TestValidateToken_ValidToken2087=== RUN TestValidateToken_WrongAudience2088=== PAUSE TestValidateToken_WrongAudience2089=== RUN TestValidateToken_Expired2090=== PAUSE TestValidateToken_Expired2091=== RUN TestValidateToken_BoundClaimsMismatch2092=== PAUSE TestValidateToken_BoundClaimsMismatch2093=== RUN TestValidateToken_BoundSubjectMismatch2094=== PAUSE TestValidateToken_BoundSubjectMismatch2095=== RUN TestValidateToken_MultipleProviders2096=== PAUSE TestValidateToken_MultipleProviders2097=== RUN TestValidateToken_NoMatchingProvider2098=== PAUSE TestValidateToken_NoMatchingProvider2099=== RUN TestValidateToken_KubernetesServiceAccount2100=== PAUSE TestValidateToken_KubernetesServiceAccount2101=== RUN TestNewValidator_KubernetesRequiresCA2102=== PAUSE TestNewValidator_KubernetesRequiresCA2103=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2104=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2105=== RUN TestPins_ReservedForMatchingRule2106=== PAUSE TestPins_ReservedForMatchingRule2107=== RUN TestPins_TopLevelShorthand2108=== PAUSE TestPins_TopLevelShorthand2109=== RUN TestPins_ConfigValidation2110=== PAUSE TestPins_ConfigValidation2111=== RUN TestScopes_LegacyProviderDefaultsToWrite2112=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2113=== RUN TestScopes_Rules2114=== PAUSE TestScopes_Rules2115=== RUN TestScopes_ConfigValidation2116=== PAUSE TestScopes_ConfigValidation2117=== CONT TestAudienceForIssuer2118=== CONT TestValidateToken_KubernetesServiceAccount2119--- PASS: TestAudienceForIssuer (0.00s)2120=== CONT TestValidateToken_Expired2121=== CONT TestValidateToken_BoundClaimsMismatch2122=== CONT TestValidateToken_MultipleProviders2123=== CONT TestValidateToken_WrongAudience2124=== CONT TestValidateToken_ValidToken2125=== CONT TestGlobMatch2126=== RUN TestGlobMatch/foo_foo2127=== PAUSE TestGlobMatch/foo_foo2128=== RUN TestGlobMatch/foo_bar2129=== PAUSE TestGlobMatch/foo_bar2130=== RUN TestGlobMatch/*_2131=== PAUSE TestGlobMatch/*_2132=== RUN TestGlobMatch/*_anything2133=== PAUSE TestGlobMatch/*_anything2134=== RUN TestGlobMatch/foo*_foo2135=== PAUSE TestGlobMatch/foo*_foo2136=== CONT TestPins_ConfigValidation2137=== CONT TestScopes_ConfigValidation2138=== CONT TestScopes_Rules2139=== CONT TestScopes_LegacyProviderDefaultsToWrite2140=== CONT TestPins_ReservedForMatchingRule2141=== CONT TestPins_TopLevelShorthand2142=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2143=== CONT TestValidateToken_NoMatchingProvider2144=== CONT TestNewValidator_KubernetesRequiresCA2145=== CONT TestValidateToken_BoundSubjectMismatch2146=== RUN TestGlobMatch/foo*_foobar2147=== PAUSE TestGlobMatch/foo*_foobar2148=== RUN TestGlobMatch/foo*_bar2149=== PAUSE TestGlobMatch/foo*_bar2150=== RUN TestGlobMatch/*bar_bar2151=== PAUSE TestGlobMatch/*bar_bar2152=== RUN TestGlobMatch/*bar_foobar2153=== PAUSE TestGlobMatch/*bar_foobar2154=== RUN TestGlobMatch/*bar_foo2155=== PAUSE TestGlobMatch/*bar_foo2156=== RUN TestGlobMatch/foo*bar_foobar2157=== PAUSE TestGlobMatch/foo*bar_foobar2158=== RUN TestGlobMatch/foo*bar_foo123bar2159=== PAUSE TestGlobMatch/foo*bar_foo123bar2160=== RUN TestGlobMatch/foo*bar_foobarbaz2161=== PAUSE TestGlobMatch/foo*bar_foobarbaz2162=== RUN TestGlobMatch/*/*_foo/bar2163=== PAUSE TestGlobMatch/*/*_foo/bar2164=== RUN TestGlobMatch/*/*_foo2165=== PAUSE TestGlobMatch/*/*_foo2166=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2167=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2168=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02169=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02170=== RUN TestGlobMatch/refs/*/main_refs/heads/main2171=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2172=== RUN TestGlobMatch/fo?_foo2173=== PAUSE TestGlobMatch/fo?_foo2174=== RUN TestGlobMatch/fo?_fo2175=== PAUSE TestGlobMatch/fo?_fo2176=== RUN TestGlobMatch/fo?_fooo2177=== PAUSE TestGlobMatch/fo?_fooo2178=== RUN TestGlobMatch/?oo_foo2179=== PAUSE TestGlobMatch/?oo_foo2180=== RUN TestGlobMatch/?oo_boo2181=== PAUSE TestGlobMatch/?oo_boo2182=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2183=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2184=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2185=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2186=== CONT TestGlobMatch/foo_foo2187=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2188=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2189=== CONT TestGlobMatch/?oo_boo2190=== CONT TestGlobMatch/?oo_foo2191=== CONT TestGlobMatch/fo?_fooo2192=== CONT TestGlobMatch/fo?_fo2193=== CONT TestGlobMatch/fo?_foo2194=== CONT TestGlobMatch/refs/*/main_refs/heads/main2195=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02196=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2197=== CONT TestGlobMatch/*/*_foo2198=== CONT TestGlobMatch/*/*_foo/bar2199=== CONT TestGlobMatch/foo*bar_foobarbaz2200=== CONT TestGlobMatch/foo*bar_foo123bar2201=== CONT TestGlobMatch/foo*bar_foobar2202=== CONT TestGlobMatch/*bar_foo2203=== CONT TestGlobMatch/*bar_foobar2204=== CONT TestGlobMatch/*bar_bar2205=== CONT TestGlobMatch/foo*_bar2206=== CONT TestGlobMatch/foo*_foobar2207=== CONT TestGlobMatch/foo*_foo2208=== CONT TestGlobMatch/*_anything2209=== CONT TestGlobMatch/*_2210=== CONT TestGlobMatch/foo_bar2211--- PASS: TestGlobMatch (0.00s)2212 --- PASS: TestGlobMatch/foo_foo (0.00s)2213 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2214 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2215 --- PASS: TestGlobMatch/?oo_boo (0.00s)2216 --- PASS: TestGlobMatch/?oo_foo (0.00s)2217 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2218 --- PASS: TestGlobMatch/fo?_fo (0.00s)2219 --- PASS: TestGlobMatch/fo?_foo (0.00s)2220 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2221 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2222 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2223 --- PASS: TestGlobMatch/*/*_foo (0.00s)2224 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2225 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2226 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2227 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2228 --- PASS: TestGlobMatch/*bar_foo (0.00s)2229 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2230 --- PASS: TestGlobMatch/*bar_bar (0.00s)2231 --- PASS: TestGlobMatch/foo*_bar (0.00s)2232 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2233 --- PASS: TestGlobMatch/foo*_foo (0.00s)2234 --- PASS: TestGlobMatch/*_anything (0.00s)2235 --- PASS: TestGlobMatch/*_ (0.00s)2236 --- PASS: TestGlobMatch/foo_bar (0.00s)2237--- PASS: TestPins_ConfigValidation (0.00s)2238--- PASS: TestScopes_ConfigValidation (0.00s)22392026/10/07 09:36:28 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:328592240--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)22412026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39581/oidc2242--- PASS: TestScopes_Rules (0.06s)22432026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40971/oidc2244--- PASS: TestValidateToken_WrongAudience (0.07s)22452026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32937/oidc2246--- PASS: TestValidateToken_ValidToken (0.08s)22472026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38135/oidc2248--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)22492026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33683/oidc2250--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)22512026/10/07 09:36:28 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40713/oidc22522026/10/07 09:36:28 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35841/oidc2253--- PASS: TestValidateToken_MultipleProviders (0.11s)22542026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42837/oidc22552026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46703/oidc2256--- PASS: TestValidateToken_Expired (0.11s)2257--- PASS: TestPins_TopLevelShorthand (0.11s)22582026/10/07 09:36:28 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232259--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.18s)22602026/10/07 09:36:28 http: TLS handshake error from 127.0.0.1:58988: remote error: tls: bad certificate2261--- PASS: TestNewValidator_KubernetesRequiresCA (0.20s)22622026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43843/oidc2263--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.21s)22642026/10/07 09:36:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36065/oidc2265--- PASS: TestPins_ReservedForMatchingRule (0.37s)22662026/10/07 09:36:28 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42807/oidc2267--- PASS: TestValidateToken_NoMatchingProvider (0.51s)2268PASS2269Running hook tests...2270=== RUN TestSendPathsEmpty2271=== PAUSE TestSendPathsEmpty2272=== RUN TestQueueEnqueueAndFetch2273=== PAUSE TestQueueEnqueueAndFetch2274=== RUN TestQueueDeduplication2275=== PAUSE TestQueueDeduplication2276=== RUN TestQueueRemove2277=== PAUSE TestQueueRemove2278=== RUN TestQueueFetchBatchLimit2279=== PAUSE TestQueueFetchBatchLimit2280=== RUN TestQueueRetryMovesToBack2281=== PAUSE TestQueueRetryMovesToBack2282=== RUN TestQueueFetchRemoveLifecycle2283=== PAUSE TestQueueFetchRemoveLifecycle2284=== RUN TestQueueConcurrentWriters2285=== PAUSE TestQueueConcurrentWriters2286=== RUN TestQueueRemoveLargeClosure2287=== PAUSE TestQueueRemoveLargeClosure2288=== RUN TestServerClientIntegration2289--- PASS: TestServerClientIntegration (0.00s)2290=== RUN TestServerQueueError22912026/10/07 09:36:28 ERROR Failed to queue paths error="permission denied" count=12292--- PASS: TestServerQueueError (0.00s)2293=== RUN TestGetListenerSocketActivation2294 server_test.go:219: === RUN TestGetListenerSocketActivation2295 --- PASS: TestGetListenerSocketActivation (0.00s)2296 PASS2297 2298--- PASS: TestGetListenerSocketActivation (0.01s)2299=== RUN TestDrainIsolatesPoisonPath2300=== PAUSE TestDrainIsolatesPoisonPath2301=== RUN TestRunNotBlockedByPoisonHead2302=== PAUSE TestRunNotBlockedByPoisonHead2303=== RUN TestDrainGivesUpWhenServerDown2304=== PAUSE TestDrainGivesUpWhenServerDown2305=== RUN TestFailedPathPrunedByLaterClosure2306=== PAUSE TestFailedPathPrunedByLaterClosure2307=== RUN TestWorkerUploadsAndRemoves2308=== PAUSE TestWorkerUploadsAndRemoves2309=== RUN TestWorkerSkipsGCdPaths2310=== PAUSE TestWorkerSkipsGCdPaths2311=== RUN TestWorkerPrunesClosureDeps2312=== PAUSE TestWorkerPrunesClosureDeps2313=== RUN TestDrainTimeout2314=== PAUSE TestDrainTimeout2315=== CONT TestSendPathsEmpty2316=== CONT TestWorkerSkipsGCdPaths2317--- PASS: TestSendPathsEmpty (0.00s)2318=== CONT TestQueueRemoveLargeClosure2319=== CONT TestWorkerPrunesClosureDeps2320=== CONT TestDrainTimeout2321=== CONT TestQueueFetchBatchLimit2322=== CONT TestQueueRemove2323=== CONT TestQueueConcurrentWriters2324=== CONT TestQueueDeduplication2325=== CONT TestQueueEnqueueAndFetch2326=== CONT TestQueueRetryMovesToBack2327=== CONT TestQueueFetchRemoveLifecycle2328=== CONT TestDrainGivesUpWhenServerDown2329=== CONT TestWorkerUploadsAndRemoves2330=== CONT TestFailedPathPrunedByLaterClosure2331=== CONT TestRunNotBlockedByPoisonHead2332=== CONT TestDrainIsolatesPoisonPath23332026/10/07 09:36:28 INFO Upload queue status pending=223342026/10/07 09:36:28 INFO Upload queue status pending=223352026/10/07 09:36:28 INFO Uploading batch count=223362026/10/07 09:36:28 INFO Uploading batch count=123372026/10/07 09:36:28 INFO Upload queue status pending=223382026/10/07 09:36:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths29431472/002/nonexistent23392026/10/07 09:36:28 INFO Upload queue status pending=323402026/10/07 09:36:28 INFO Uploading batch count=12341--- PASS: TestQueueFetchBatchLimit (0.01s)23422026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=12343--- PASS: TestQueueRetryMovesToBack (0.01s)23442026/10/07 09:36:28 INFO Uploading batch count=123452026/10/07 09:36:28 INFO Uploading batch count=123462026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=123472026/10/07 09:36:28 INFO Uploading batch count=22348--- PASS: TestQueueDeduplication (0.02s)23492026/10/07 09:36:28 INFO Uploading batch count=423502026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=42351--- PASS: TestQueueRemove (0.02s)23522026/10/07 09:36:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1796727893/002/bbb23532026/10/07 09:36:28 INFO Uploading batch count=223542026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=223552026/10/07 09:36:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3502915960/002/a2356--- PASS: TestQueueEnqueueAndFetch (0.02s)2357--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23582026/10/07 09:36:28 INFO Uploading batch count=123592026/10/07 09:36:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3502915960/002/b23602026/10/07 09:36:28 INFO Uploading batch count=223612026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=223622026/10/07 09:36:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3502915960/002/c23632026/10/07 09:36:28 INFO Uploading batch count=123642026/10/07 09:36:28 INFO Uploading batch count=123652026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=123662026/10/07 09:36:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3502915960/002/d23672026/10/07 09:36:28 INFO Uploading batch count=123682026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=123692026/10/07 09:36:28 INFO Uploading batch count=223702026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=223712026/10/07 09:36:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3502915960/002/e23722026/10/07 09:36:28 INFO Uploading batch count=123732026/10/07 09:36:28 ERROR Upload failed error="upload failed" count=123742026/10/07 09:36:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3502915960/002/f23752026/10/07 09:36:28 ERROR Drain finished with paths left in queue remaining=12376--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23772026/10/07 09:36:28 ERROR Drain finished with paths left in queue remaining=102378--- PASS: TestDrainIsolatesPoisonPath (0.02s)2379--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2380--- PASS: TestWorkerUploadsAndRemoves (0.03s)2381--- PASS: TestWorkerPrunesClosureDeps (0.03s)2382--- PASS: TestWorkerSkipsGCdPaths (0.04s)2383--- PASS: TestQueueRemoveLargeClosure (0.10s)2384--- PASS: TestQueueConcurrentWriters (0.16s)23852026/10/07 09:36:29 ERROR Upload failed error="context deadline exceeded" count=223862026/10/07 09:36:29 ERROR Drain finished with paths left in queue remaining=42387--- PASS: TestDrainTimeout (0.22s)23882026/10/07 09:36:29 INFO Uploading batch count=123892026/10/07 09:36:29 INFO Uploading batch count=123902026/10/07 09:36:29 INFO Uploading batch count=123912026/10/07 09:36:29 ERROR Upload failed error="upload failed" count=123922026/10/07 09:36:29 INFO Uploading batch count=123932026/10/07 09:36:29 ERROR Upload failed error="upload failed" count=123942026/10/07 09:36:29 INFO Uploading batch count=123952026/10/07 09:36:29 ERROR Upload failed error="upload failed" count=123962026/10/07 09:36:29 INFO Uploading batch count=123972026/10/07 09:36:29 ERROR Upload failed error="upload failed" count=123982026/10/07 09:36:29 ERROR Drain finished with paths left in queue remaining=12399--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2400PASS2401Running signing tests...2402=== RUN TestExternalSigner2403=== PAUSE TestExternalSigner2404=== RUN TestExternalSignerWrongPublicKey2405=== PAUSE TestExternalSignerWrongPublicKey2406=== RUN TestExternalSignerErrors2407=== PAUSE TestExternalSignerErrors2408=== RUN TestExternalSignerRestartsAfterCrash2409=== PAUSE TestExternalSignerRestartsAfterCrash2410=== RUN TestExternalSignerProgramErrorKeepsProcess2411=== PAUSE TestExternalSignerProgramErrorKeepsProcess2412=== RUN TestExternalSignerClose2413=== PAUSE TestExternalSignerClose2414=== RUN TestExternalSignerRejectsInvalidPublicKey2415=== PAUSE TestExternalSignerRejectsInvalidPublicKey2416=== RUN TestExternalSignerCancellation2417=== PAUSE TestExternalSignerCancellation2418=== RUN TestGenerateFingerprint2419=== PAUSE TestGenerateFingerprint2420=== RUN TestParseSigningKey2421=== PAUSE TestParseSigningKey2422=== RUN TestSign2423=== PAUSE TestSign2424=== RUN TestSignBatch2425=== PAUSE TestSignBatch2426=== RUN TestNilKeyPublicKey2427=== PAUSE TestNilKeyPublicKey2428=== RUN TestSignErrors2429=== PAUSE TestSignErrors2430=== CONT TestExternalSigner2431=== CONT TestExternalSignerCancellation2432=== CONT TestExternalSignerRestartsAfterCrash2433=== CONT TestExternalSignerProgramErrorKeepsProcess2434=== CONT TestExternalSignerRejectsInvalidPublicKey2435=== RUN TestExternalSignerRejectsInvalidPublicKey/#002436=== CONT TestExternalSignerClose2437=== CONT TestSignErrors2438=== CONT TestNilKeyPublicKey2439--- PASS: TestNilKeyPublicKey (0.00s)2440=== CONT TestSignBatch2441=== CONT TestSign2442=== CONT TestParseSigningKey2443=== RUN TestParseSigningKey/valid_32-byte_key2444=== PAUSE TestParseSigningKey/valid_32-byte_key2445=== CONT TestGenerateFingerprint2446=== RUN TestGenerateFingerprint/basic_with_references2447=== PAUSE TestGenerateFingerprint/basic_with_references2448=== CONT TestExternalSignerWrongPublicKey2449=== CONT TestExternalSignerErrors2450=== RUN TestExternalSignerErrors/exit_at_startup2451=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002452=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2453=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2454=== RUN TestParseSigningKey/no_colon2455=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2456=== PAUSE TestExternalSignerErrors/exit_at_startup2457=== PAUSE TestParseSigningKey/no_colon2458=== RUN TestParseSigningKey/empty_name2459=== RUN TestExternalSignerErrors/exit_on_request2460=== PAUSE TestExternalSignerErrors/exit_on_request2461=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2462=== RUN TestExternalSignerErrors/invalid_signature_base642463=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2464=== PAUSE TestExternalSignerErrors/invalid_signature_base642465=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2466=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2467=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2468=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2469=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2470=== CONT TestExternalSignerRejectsInvalidPublicKey/#002471=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2472=== RUN TestExternalSignerErrors/invalid_JSON2473=== RUN TestGenerateFingerprint/no_references2474=== PAUSE TestGenerateFingerprint/no_references2475=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2476=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2477=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2478=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2479=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2480=== RUN TestGenerateFingerprint/invalid_nar_hash_length2481=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2482=== RUN TestGenerateFingerprint/invalid_store_path_prefix2483=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2484=== RUN TestGenerateFingerprint/invalid_reference_prefix2485=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2486=== CONT TestGenerateFingerprint/basic_with_references2487=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2488=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2489=== CONT TestGenerateFingerprint/invalid_reference_prefix2490=== CONT TestGenerateFingerprint/no_references2491=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2492--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2493 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2494 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2495 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2496 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2497 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2498=== PAUSE TestExternalSignerErrors/invalid_JSON2499=== RUN TestExternalSignerErrors/wrong_shape2500=== PAUSE TestParseSigningKey/empty_name2501=== CONT TestGenerateFingerprint/invalid_nar_hash_length2502=== CONT TestGenerateFingerprint/invalid_store_path_prefix2503=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2504=== PAUSE TestExternalSignerErrors/wrong_shape2505=== RUN TestParseSigningKey/invalid_base642506--- PASS: TestGenerateFingerprint (0.00s)2507 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2508 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2509 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2510 --- PASS: TestGenerateFingerprint/no_references (0.00s)2511 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2512 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2513 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2514=== RUN TestExternalSignerErrors/wrong_id2515=== PAUSE TestParseSigningKey/invalid_base642516=== PAUSE TestExternalSignerErrors/wrong_id2517=== RUN TestParseSigningKey/wrong_length2518=== RUN TestExternalSignerErrors/missing_signatures2519=== PAUSE TestExternalSignerErrors/missing_signatures2520=== PAUSE TestParseSigningKey/wrong_length2521=== CONT TestParseSigningKey/valid_32-byte_key2522=== CONT TestParseSigningKey/invalid_base642523=== CONT TestParseSigningKey/empty_name2524=== RUN TestExternalSignerErrors/too_few_signatures2525=== PAUSE TestExternalSignerErrors/too_few_signatures2526=== RUN TestExternalSignerErrors/unrequested_key2527=== CONT TestParseSigningKey/no_colon2528=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2529=== CONT TestParseSigningKey/wrong_length2530=== PAUSE TestExternalSignerErrors/unrequested_key2531=== RUN TestExternalSignerErrors/missing_signature_name2532=== PAUSE TestExternalSignerErrors/missing_signature_name2533=== RUN TestExternalSignerErrors/wrong_signature_length2534=== PAUSE TestExternalSignerErrors/wrong_signature_length2535=== RUN TestExternalSignerErrors/program_error2536=== PAUSE TestExternalSignerErrors/program_error2537=== RUN TestExternalSignerErrors/null2538=== PAUSE TestExternalSignerErrors/null2539=== RUN TestExternalSignerErrors/null_signatures2540=== PAUSE TestExternalSignerErrors/null_signatures2541=== RUN TestExternalSignerErrors/wrong_signatures_shape2542=== RUN TestSignErrors/nil_key2543=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2544=== PAUSE TestSignErrors/nil_key2545=== RUN TestExternalSignerErrors/wrong_signature_name2546=== PAUSE TestExternalSignerErrors/wrong_signature_name2547=== CONT TestExternalSignerErrors/exit_at_startup2548=== CONT TestExternalSignerErrors/missing_signature_name2549=== CONT TestExternalSignerErrors/null_signatures2550=== CONT TestExternalSignerErrors/unrequested_key2551=== CONT TestExternalSignerErrors/wrong_id2552=== CONT TestExternalSignerErrors/too_few_signatures2553=== CONT TestExternalSignerErrors/program_error2554=== CONT TestExternalSignerErrors/null2555=== CONT TestExternalSignerErrors/wrong_signature_name2556=== RUN TestSignErrors/nil_narinfo2557=== PAUSE TestSignErrors/nil_narinfo2558=== CONT TestExternalSignerErrors/wrong_signature_length2559=== CONT TestExternalSignerErrors/invalid_JSON2560=== CONT TestExternalSignerErrors/wrong_shape2561=== CONT TestExternalSignerErrors/missing_signatures2562--- PASS: TestParseSigningKey (0.00s)2563 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2564 --- PASS: TestParseSigningKey/empty_name (0.00s)2565 --- PASS: TestParseSigningKey/no_colon (0.00s)2566 --- PASS: TestParseSigningKey/wrong_length (0.00s)2567 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2568 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2569--- PASS: TestSign (0.00s)2570--- PASS: TestSignBatch (0.00s)2571=== CONT TestExternalSignerErrors/exit_on_request2572=== CONT TestExternalSignerErrors/invalid_signature_base642573=== CONT TestExternalSignerErrors/wrong_signatures_shape2574=== RUN TestSignErrors/invalid_narinfo2575=== PAUSE TestSignErrors/invalid_narinfo2576=== RUN TestSignErrors/canceled2577=== PAUSE TestSignErrors/canceled2578=== CONT TestSignErrors/nil_key2579=== CONT TestSignErrors/canceled2580=== CONT TestSignErrors/invalid_narinfo2581=== CONT TestSignErrors/nil_narinfo2582--- PASS: TestSignErrors (0.01s)2583 --- PASS: TestSignErrors/nil_key (0.00s)2584 --- PASS: TestSignErrors/canceled (0.00s)2585 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2586 --- PASS: TestSignErrors/nil_narinfo (0.00s)2587--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2588--- PASS: TestExternalSignerWrongPublicKey (0.01s)2589--- PASS: TestExternalSignerClose (0.01s)2590--- PASS: TestExternalSigner (0.01s)2591--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2592--- PASS: TestExternalSignerErrors (0.00s)2593 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2594 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2595 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2596 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2597 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2598 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2599 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2600 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2601 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2602 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2603 --- PASS: TestExternalSignerErrors/null (0.01s)2604 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2605 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2606 --- PASS: TestExternalSignerErrors/program_error (0.01s)2607 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2608 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2609--- PASS: TestExternalSignerCancellation (0.02s)2610PASS2611Running OpenBao signer tests...2612=== RUN TestSign2613=== PAUSE TestSign2614=== RUN TestSignErrors2615=== PAUSE TestSignErrors2616=== RUN TestServe2617=== PAUSE TestServe2618=== RUN TestServeRejectsGarbage2619=== PAUSE TestServeRejectsGarbage2620=== CONT TestSign2621=== CONT TestServe2622=== CONT TestServeRejectsGarbage2623=== CONT TestSignErrors2624=== RUN TestSignErrors/no_prefix2625--- PASS: TestServeRejectsGarbage (0.00s)2626=== PAUSE TestSignErrors/no_prefix2627=== RUN TestSignErrors/invalid_base642628=== PAUSE TestSignErrors/invalid_base642629=== RUN TestSignErrors/http_error2630=== PAUSE TestSignErrors/http_error2631=== RUN TestSignErrors/invalid_json2632=== PAUSE TestSignErrors/invalid_json2633=== CONT TestSignErrors/no_prefix2634=== CONT TestSignErrors/http_error2635--- PASS: TestServe (0.00s)2636=== CONT TestSignErrors/invalid_base642637=== CONT TestSignErrors/invalid_json2638--- PASS: TestSignErrors (0.00s)2639 --- PASS: TestSignErrors/invalid_base64 (0.00s)2640 --- PASS: TestSignErrors/http_error (0.00s)2641 --- PASS: TestSignErrors/invalid_json (0.00s)2642 --- PASS: TestSignErrors/no_prefix (0.01s)2643--- PASS: TestSign (0.01s)2644PASS