niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #377
· raw
1tribuchet: building on jamie2Running 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.04s)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 TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== CONT TestSetClientTLSDoesNotMutateDefaultTransport103=== CONT TestStreamPushIsolatesFailures104=== CONT TestResolveStorePath105=== CONT TestSetClientTLSErrors106=== CONT TestRegisterUploadedObjectReusesConnections1072026/10/06 11:18:16 ERROR Upload failed error="bad path" count=3108--- PASS: TestResolveStorePath (0.00s)109=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1102026/10/06 11:18:16 WARN Rate limiter enabled after throttle name=server-test rate=5111--- PASS: TestStreamPushIsolatesFailures (0.00s)112=== CONT TestPathInfoHashCompatibility113=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)114=== CONT TestConvertHashToNix32115=== RUN TestConvertHashToNix32/SRI_format_to_Nix32116=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32117=== RUN TestConvertHashToNix32/already_Nix32_format118=== PAUSE TestConvertHashToNix32/already_Nix32_format119=== RUN TestConvertHashToNix32/invalid_format120=== PAUSE TestConvertHashToNix32/invalid_format121=== CONT TestGetStorePathHash122=== RUN TestGetStorePathHash/valid_store_path123=== PAUSE TestGetStorePathHash/valid_store_path124=== RUN TestGetStorePathHash/basename_without_hyphen_should_error125=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error126=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error127=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error128=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error129=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error130=== CONT TestRateLimiterFeedback131=== RUN TestRateLimiterFeedback/429_enables_limiter132=== PAUSE TestRateLimiterFeedback/429_enables_limiter133=== CONT TestDumpPathWriterError134=== CONT TestStreamPushBatchesUnderLoad135=== CONT TestDumpPathSingleFile136=== CONT TestDumpPathMatchesNix137=== CONT TestUploadMultipart_SupersededByPeer138=== CONT TestPartSizeForNAR139=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun140=== CONT TestFilterOversizedClosures141=== CONT TestCaseHackSuffix142=== CONT TestStreamPushGivesUpOnDeadServer143=== CONT TestUploadMultipart_PartsInParallel144=== CONT TestStreamPushReportsEveryPath145=== CONT TestShellSplitErrors146=== CONT TestShellSplit147--- PASS: TestShellSplit (0.00s)148=== CONT TestParsePathInfoJSONMultiplePaths149=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths150=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths152=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon156=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI157=== RUN TestEncodeNixBase32/test_string_hash158=== CONT TestParsePathInfoJSON159=== RUN TestUploadMultipart_SupersededByPeer/exists160=== CONT TestPathInfoCACompatibility161--- PASS: TestShellSplitErrors (0.00s)162=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica163=== PAUSE TestEncodeNixBase32/test_string_hash164=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI165=== RUN TestRateLimiterFeedback/503_enables_limiter166=== PAUSE TestRateLimiterFeedback/503_enables_limiter167=== CONT TestConvertHashToNix32/SRI_format_to_Nix32168=== PAUSE TestUploadMultipart_SupersededByPeer/exists169--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)170--- PASS: TestDoServerRequestAttachesToken (0.02s)171=== CONT TestEncodeNixBase32WithRealHash172--- PASS: TestEncodeNixBase32WithRealHash (0.00s)173=== CONT TestGetStorePathHash/valid_store_path174=== RUN TestPathInfoCACompatibility/null_ca_field175=== RUN TestSetClientTLSErrors/missing_cert_file176=== RUN TestEncodeNixBase32/empty_input177=== RUN TestPartSizeForNAR/zero_stays_at_minimum178--- PASS: TestStreamPushReportsEveryPath (0.02s)1792026/10/06 11:18:16 ERROR Upload failed error="connection refused" count=201802026/10/06 11:18:16 ERROR Server seems unavailable, giving up on batch untried=171812026/10/06 11:18:16 INFO Garbage collection started182=== CONT TestSetClientTLS183=== CONT TestClientSignaturesByStorePath184=== CONT TestStreamPushReportsSignatures185=== PAUSE TestPathInfoCACompatibility/null_ca_field186=== PAUSE TestSetClientTLSErrors/missing_cert_file187=== PAUSE TestEncodeNixBase32/empty_input1882026/10/06 11:18:16 WARN Rate limiter enabled after throttle name=server-test rate=5189=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum1902026/10/06 11:18:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41949191=== CONT TestConvertHashToNix32/invalid_format192=== RUN TestPartSizeForNAR/small_stays_at_minimum193=== CONT TestConvertHashToNix32/already_Nix32_format194=== CONT TestScriptTokenEmptyCommand1952026/10/06 11:18:16 ERROR Upload failed error=boom count=1196=== CONT TestScriptTokenScriptFails197=== CONT TestScriptTokenBadJSON1982026/10/06 11:18:16 WARN Rate limiter backed off name=server-test rate=51992026/10/06 11:18:16 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:419492002026/10/06 11:18:16 INFO Garbage collection started201=== CONT TestScriptTokenEmptyToken2022026/10/06 11:18:16 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=0203=== RUN TestSetClientTLS/rejects_connection_without_client_cert204=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert205=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA206=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA207=== RUN TestSetClientTLS/preserves_debug_logging_transport208=== PAUSE TestSetClientTLS/preserves_debug_logging_transport209=== CONT TestScriptTokenCachesUntilRefresh210=== CONT TestScriptTokenNoExpiryRerunsEveryCall211=== PAUSE TestPartSizeForNAR/small_stays_at_minimum212=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum213=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum214=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts215=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts216=== RUN TestPartSizeForNAR/1_TiB217=== PAUSE TestPartSizeForNAR/1_TiB218=== RUN TestPartSizeForNAR/5_TiB_S3_max_object219=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object220=== RUN TestPartSizeForNAR/capped_at_5_GiB221=== PAUSE TestPartSizeForNAR/capped_at_5_GiB222=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter223=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter224=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter225=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter226=== RUN TestParsePathInfoJSON/Nix_format227=== PAUSE TestParsePathInfoJSON/Nix_format228=== RUN TestParsePathInfoJSON/Lix_format229=== PAUSE TestParsePathInfoJSON/Lix_format230=== RUN TestParsePathInfoJSON/empty_input231=== PAUSE TestParsePathInfoJSON/empty_input232=== CONT TestFileTokenEmpty2332026/10/06 11:18:16 WARN Garbage collection finished on another replica. Its statistics are not available here234=== CONT TestStaticToken235=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths236=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error237=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error238=== CONT TestGetStorePathHash/basename_without_hyphen_should_error239=== CONT TestEncodeNixBase32/test_string_hash240=== CONT TestEncodeNixBase32/empty_input241=== CONT TestSetClientTLS/rejects_connection_without_client_cert242=== CONT TestSetClientTLS/preserves_debug_logging_transport243=== CONT TestPartSizeForNAR/zero_stays_at_minimum244=== CONT TestPartSizeForNAR/1_TiB245=== CONT TestPartSizeForNAR/capped_at_5_GiB246=== CONT TestPartSizeForNAR/5_TiB_S3_max_object247=== CONT TestRateLimiterFeedback/429_enables_limiter248=== CONT TestFileTokenReadsAndCaches249=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum250=== CONT TestPartSizeForNAR/small_stays_at_minimum251=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2522026/10/06 11:18:16 WARN Rate limiter enabled after throttle name=server-test rate=52532026/10/06 11:18:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:46387254=== CONT TestRateLimiterFeedback/503_enables_limiter255=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5122562026/10/06 11:18:16 WARN Rate limiter backed off name=server-test rate=5257=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512258=== RUN TestFilterOversizedClosures/no_limit_keeps_everything259=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything260=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter261=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2622026/10/06 11:18:16 WARN Rate limiter enabled after throttle name=server-test rate=52632026/10/06 11:18:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44395264=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped266=== RUN TestFilterOversizedClosures/all_closures_skipped267=== PAUSE TestFilterOversizedClosures/all_closures_skipped2682026/10/06 11:18:16 WARN Rate limiter backed off name=server-test rate=5269=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512270=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths271=== RUN TestPathInfoCACompatibility/old_string_format_-_text272=== RUN TestSetClientTLSErrors/missing_key_file273--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)274=== RUN TestParsePathInfoJSON/whitespace_only275=== RUN TestUploadMultipart_SupersededByPeer/missing276=== CONT TestFileTokenMissing277=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts278=== CONT TestStreamPushRequestLine279=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)280=== CONT TestFilterOversizedClosures/no_limit_keeps_everything281=== CONT TestFilterOversizedClosures/all_closures_skipped282=== PAUSE TestParsePathInfoJSON/whitespace_only2832026/10/06 11:18:16 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=50284=== RUN TestParsePathInfoJSON/invalid_JSON285=== PAUSE TestParsePathInfoJSON/invalid_JSON286=== CONT TestParsePathInfoJSON/Nix_format287=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text288=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive289--- PASS: TestClientSignaturesByStorePath (0.00s)290--- PASS: TestConvertHashToNix32 (0.00s)291 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)292 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)293 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)294--- PASS: TestScriptTokenEmptyCommand (0.00s)295=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon296=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped297=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive298=== PAUSE TestUploadMultipart_SupersededByPeer/missing299=== PAUSE TestSetClientTLSErrors/missing_key_file300=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI301=== CONT TestParsePathInfoJSON/invalid_JSON302=== CONT TestParsePathInfoJSON/empty_input303=== CONT TestParsePathInfoJSON/Lix_format304--- PASS: TestStreamPushReportsSignatures (0.00s)305=== CONT TestParsePathInfoJSON/whitespace_only306--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)307--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)308--- PASS: TestScriptTokenScriptFails (0.00s)309--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.05s)310--- PASS: TestScriptTokenBadJSON (0.00s)311--- PASS: TestStaticToken (0.00s)312--- PASS: TestFileTokenEmpty (0.00s)313--- PASS: TestDumpPathSingleFile (0.05s)314--- PASS: TestScriptTokenEmptyToken (0.00s)315--- PASS: TestFileTokenReadsAndCaches (0.00s)316--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)317 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)318 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)319=== CONT TestUploadMultipart_SupersededByPeer/exists320=== RUN TestPathInfoCACompatibility/new_structured_format_-_text3212026/10/06 11:18:16 ERROR Upload failed error=boom count=1322=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text323=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method324=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method325=== CONT TestPathInfoCACompatibility/null_ca_field326--- PASS: TestEncodeNixBase32 (0.05s)327 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)328 --- PASS: TestEncodeNixBase32/empty_input (0.00s)329--- PASS: TestPathInfoHashCompatibility (0.05s)330 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)331 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)332 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)333 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)334=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method335=== CONT TestPathInfoCACompatibility/new_structured_format_-_text336=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive337=== CONT TestPathInfoCACompatibility/old_string_format_-_text338=== RUN TestSetClientTLSErrors/missing_ca_file3392026/10/06 11:18:16 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=2000340--- PASS: TestFileTokenMissing (0.00s)341--- PASS: TestGetStorePathHash (0.00s)342 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)343 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)345 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)346--- PASS: TestParsePathInfoJSON (0.05s)347 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)348 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)349 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)350 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)351 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)352--- PASS: TestPartSizeForNAR (0.05s)353 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)354 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)355 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)356 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)357 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)358 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)359 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)360--- PASS: TestPathInfoCACompatibility (0.06s)361 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)362 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)363 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)364 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)365 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)366--- PASS: TestRateLimiterFeedback (0.05s)367 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)369 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)370 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)371--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)372--- PASS: TestFilterOversizedClosures (0.03s)373 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)374 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)375 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)376=== PAUSE TestSetClientTLSErrors/missing_ca_file377=== CONT TestUploadMultipart_SupersededByPeer/missing378=== RUN TestSetClientTLSErrors/invalid_ca_file379=== PAUSE TestSetClientTLSErrors/invalid_ca_file380=== CONT TestSetClientTLSErrors/missing_cert_file381=== CONT TestSetClientTLSErrors/missing_ca_file382--- PASS: TestUploadMultipart_SupersededByPeer (0.06s)383 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)384 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)385=== CONT TestSetClientTLSErrors/missing_key_file386=== CONT TestSetClientTLSErrors/invalid_ca_file387--- PASS: TestSetClientTLSErrors (0.06s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)391 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3922026/10/06 11:18:16 http: TLS handshake error from 127.0.0.1:52362: 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: TestRegisterUploadedObjectReusesConnections (0.07s)398--- PASS: TestStreamPushRequestLine (0.02s)399--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)400--- PASS: TestDumpPathWriterError (0.07s)401--- PASS: TestCaseHackSuffix (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.13s)404--- PASS: TestUploadMultipart_PartsInParallel (0.64s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1633574543/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/postgres1633574543/data -l logfile start434435/build/postgres1633574543:5432 - no response4362026-10-06 11:18:18.761 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 11:18:18.762 UTC [129] LOG: listening on Unix socket "/build/postgres1633574543/.s.PGSQL.5432"4382026-10-06 11:18:18.769 UTC [136] LOG: database system was shut down at 2026-10-06 11:18:18 UTC4392026-10-06 11:18:18.772 UTC [129] LOG: database system is ready to accept connections440/build/postgres1633574543:5432 - accepting connections441{"timestamp":"2026-10-06T11:18:19.074781472Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"fc2d65d9-4849-47ae-bf27-a322728572a5","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(393)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 11:18:19 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 11:18:19 INFO lead: released remote=192.0.2.1:12344892026/10/06 11:18:19 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 11:18:21 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 11:18:21 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 11:18:22.574 UTC [574] FATAL: terminating connection due to administrator command4992026/10/06 11:18:22 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 11:18:23 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 11:18:23 INFO lead: released remote=192.0.2.1:12345022026/10/06 11:18:23 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyContentNegotiation605=== PAUSE TestReadProxyContentNegotiation606=== RUN TestReadProxyNarStreaming607=== PAUSE TestReadProxyNarStreaming608=== RUN TestReadProxy404609=== PAUSE TestReadProxy404610=== RUN TestReadProxyInvalidPath611=== PAUSE TestReadProxyInvalidPath612=== RUN TestReadProxyHead613=== PAUSE TestReadProxyHead614=== RUN TestReadProxyOutlastsServerWriteTimeout615=== PAUSE TestReadProxyOutlastsServerWriteTimeout616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 11:18:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestService_AuthMiddleware693=== CONT TestPush_CompleteCommitsEveryRoot694=== CONT TestReadRedirectUsesPublicS3URL695=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT696=== CONT TestCompleteMultipartUnregistered697=== CONT TestService_verifyS3Integrity698=== CONT TestService_createPendingClosureHandler699=== CONT TestService_cleanupPendingClosuresHandler700=== CONT TestUploadHandlersRejectOversizedBody701=== CONT TestUploadHandlersRejectInvalidKeys702=== CONT TestIsValidUploadKey703=== CONT TestPendingClosureWriteTimeout704=== RUN TestIsValidUploadKey/narinfo705=== PAUSE TestIsValidUploadKey/narinfo706=== CONT TestProxyWriteTimeout707=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle708=== CONT TestSkippedUploadsHandler709=== CONT TestParseSize710=== CONT TestService_Rustfstest711=== CONT TestPresignedUploadRegisteredBeforeCommit712=== CONT TestCompletedNarNotReofferedAcrossClosures713=== CONT TestCompleteMultipartUpload_ErrorButObjectExists714=== CONT TestRedundantMultipartUpload715=== CONT TestPush_SignsNarinfosOfItsPendingObjects716=== CONT TestPush_RejectsBadRequests717=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit718=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info719=== RUN TestPendingClosureWriteTimeout/empty720=== RUN TestIsValidUploadKey/nar_zst721=== RUN TestProxyWriteTimeout/narinfo722--- PASS: TestParseSize (0.00s)7232026/10/06 11:18:24 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000724=== CONT TestPush_OverlappingRootsStoreOneRowPerKey725=== PAUSE TestIsValidUploadKey/nar_zst726=== PAUSE TestProxyWriteTimeout/narinfo727=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info728=== RUN TestProxyWriteTimeout/1_GiB_nar729=== RUN TestIsValidUploadKey/nar_xz730=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal731=== PAUSE TestPendingClosureWriteTimeout/empty732=== RUN TestPendingClosureWriteTimeout/400_objects733=== PAUSE TestPendingClosureWriteTimeout/400_objects734=== RUN TestPendingClosureWriteTimeout/670k_objects735=== PAUSE TestPendingClosureWriteTimeout/670k_objects736=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline737=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline738=== CONT TestGCTaskStore_DeduplicateSameParams739--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)740=== CONT TestReadProxyRangeRequest741=== PAUSE TestProxyWriteTimeout/1_GiB_nar742=== RUN TestProxyWriteTimeout/10_GiB_nar743=== PAUSE TestProxyWriteTimeout/10_GiB_nar744=== RUN TestProxyWriteTimeout/unknown_size745=== PAUSE TestProxyWriteTimeout/unknown_size746=== CONT TestReadRedirectKeepsNarinfoProxied747=== PAUSE TestIsValidUploadKey/nar_xz748=== RUN TestIsValidUploadKey/nar_plain749=== PAUSE TestIsValidUploadKey/nar_plain750=== RUN TestIsValidUploadKey/listing751=== PAUSE TestIsValidUploadKey/listing752=== RUN TestIsValidUploadKey/build_log753=== PAUSE TestIsValidUploadKey/build_log754=== RUN TestIsValidUploadKey/build_log_home-manager_file755=== PAUSE TestIsValidUploadKey/build_log_home-manager_file756=== RUN TestIsValidUploadKey/build_log_plus_in_name757=== PAUSE TestIsValidUploadKey/build_log_plus_in_name758=== RUN TestIsValidUploadKey/build_log_question_mark759=== PAUSE TestIsValidUploadKey/build_log_question_mark760=== RUN TestIsValidUploadKey/build_log_equals761=== PAUSE TestIsValidUploadKey/build_log_equals762=== RUN TestIsValidUploadKey/realisation763=== PAUSE TestIsValidUploadKey/realisation764=== RUN TestIsValidUploadKey/realisation_plus_in_output765=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal766=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key767=== PAUSE TestIsValidUploadKey/realisation_plus_in_output768=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key769=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key770=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key771=== RUN TestIsValidUploadKey/nix-cache-info772=== PAUSE TestIsValidUploadKey/nix-cache-info773=== CONT TestReadRedirectNar774=== RUN TestIsValidUploadKey/index.html775=== PAUSE TestIsValidUploadKey/index.html776=== RUN TestIsValidUploadKey/narinfo_key,_nar_type777=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type778=== RUN TestIsValidUploadKey/nar_key,_narinfo_type779=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type780=== RUN TestIsValidUploadKey/listing_key,_narinfo_type781=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type782=== RUN TestIsValidUploadKey/traversal783=== PAUSE TestIsValidUploadKey/traversal784=== RUN TestIsValidUploadKey/traversal_nar785=== PAUSE TestIsValidUploadKey/traversal_nar786=== RUN TestIsValidUploadKey/absolute787=== PAUSE TestIsValidUploadKey/absolute788=== RUN TestIsValidUploadKey/empty_key789=== PAUSE TestIsValidUploadKey/empty_key790=== RUN TestIsValidUploadKey/unknown_type791=== PAUSE TestIsValidUploadKey/unknown_type792=== CONT TestReadProxyDisabled793--- PASS: TestSkippedUploadsHandler (0.09s)794=== CONT TestReadProxyRootRedirectsToIndexHTML795=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure796=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure797=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart798=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart799=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts800=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts801=== CONT TestReadProxyConditionalGet8022026/10/06 11:18:24 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"803--- PASS: TestService_AuthMiddleware (0.38s)804=== CONT TestReadProxyOutlastsServerWriteTimeout8052026/10/06 11:18:24 INFO Received push request method=POST path=/api/pushes8062026/10/06 11:18:24 INFO Received complete push request method=POST path=/api/pushes/1/complete807--- PASS: TestPush_CompleteCommitsEveryRoot (0.44s)808=== CONT TestReadProxyHead809--- PASS: TestReadRedirectUsesPublicS3URL (0.45s)810=== CONT TestReadProxyInvalidPath8112026/10/06 11:18:24 INFO Received cleanup request method=DELETE path=/api/pending_closures8122026/10/06 11:18:24 INFO Aborted multipart uploads count=0 kept=08132026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures8142026/10/06 11:18:24 INFO Received cleanup request method=DELETE path=/api/pending_closures8152026/10/06 11:18:24 INFO Aborted multipart uploads count=1 kept=08162026/10/06 11:18:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8172026-10-06 11:18:24.681 UTC [645] ERROR: Closure does not exist: id=18182026-10-06 11:18:24.681 UTC [645] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8192026-10-06 11:18:24.681 UTC [645] STATEMENT: -- name: CommitPendingClosure :exec820 SELECT commit_pending_closure($1::bigint)821 822--- PASS: TestService_cleanupPendingClosuresHandler (0.47s)823=== CONT TestReadProxy4048242026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures825--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)826=== CONT TestReadProxyNarStreaming8272026/10/06 11:18:24 INFO Received push request method=POST path=/api/pushes8282026/10/06 11:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8292026/10/06 11:18:24 INFO Signed narinfos id=1 count=18302026/10/06 11:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8312026/10/06 11:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8322026/10/06 11:18:24 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8332026/10/06 11:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8342026/10/06 11:18:24 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8352026/10/06 11:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8362026/10/06 11:18:24 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18372026/10/06 11:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8382026/10/06 11:18:24 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo839--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.52s)840=== CONT TestReadProxyContentNegotiation8412026/10/06 11:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8422026/10/06 11:18:24 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst843--- PASS: TestCompleteMultipartUnregistered (0.53s)844=== CONT TestReadProxyNarinfoAlreadyDecompressed8452026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures8462026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures8472026/10/06 11:18:24 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8482026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures849--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.60s)850=== CONT TestReadProxyNarinfo8512026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures8522026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures8532026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures854--- PASS: TestService_Rustfstest (0.64s)855=== CONT TestIsValidCachePath856=== RUN TestIsValidCachePath/narinfo857=== PAUSE TestIsValidCachePath/narinfo858=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars859=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars860=== RUN TestIsValidCachePath/nar_zst861=== PAUSE TestIsValidCachePath/nar_zst862=== RUN TestIsValidCachePath/nar_xz863=== PAUSE TestIsValidCachePath/nar_xz864=== RUN TestIsValidCachePath/nar_bz2865=== PAUSE TestIsValidCachePath/nar_bz2866=== RUN TestIsValidCachePath/nar_uncompressed867=== PAUSE TestIsValidCachePath/nar_uncompressed868=== RUN TestIsValidCachePath/ls869=== PAUSE TestIsValidCachePath/ls870=== RUN TestIsValidCachePath/log871=== PAUSE TestIsValidCachePath/log872=== RUN TestIsValidCachePath/realisation873=== PAUSE TestIsValidCachePath/realisation874=== RUN TestIsValidCachePath/nix-cache-info875=== PAUSE TestIsValidCachePath/nix-cache-info876=== RUN TestIsValidCachePath/index.html877=== PAUSE TestIsValidCachePath/index.html878=== RUN TestIsValidCachePath/traversal_parent879=== PAUSE TestIsValidCachePath/traversal_parent880=== RUN TestIsValidCachePath/traversal_in_middle881=== PAUSE TestIsValidCachePath/traversal_in_middle882=== RUN TestIsValidCachePath/invalid_char_e883=== PAUSE TestIsValidCachePath/invalid_char_e884=== RUN TestIsValidCachePath/invalid_char_u885=== PAUSE TestIsValidCachePath/invalid_char_u886=== RUN TestIsValidCachePath/random_path887=== PAUSE TestIsValidCachePath/random_path888=== RUN TestIsValidCachePath/empty889=== PAUSE TestIsValidCachePath/empty890=== RUN TestIsValidCachePath/leading_slash891=== PAUSE TestIsValidCachePath/leading_slash892=== RUN TestIsValidCachePath/wrong_extension893=== PAUSE TestIsValidCachePath/wrong_extension894=== RUN TestIsValidCachePath/short_hash895=== PAUSE TestIsValidCachePath/short_hash896=== CONT TestProxyHeadersOnlyTrustedOnSocket8972026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures8982026/10/06 11:18:24 INFO Received push request method=POST path=/api/pushes899--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.70s)900=== CONT TestParseSingleRange901=== RUN TestParseSingleRange/none902=== PAUSE TestParseSingleRange/none903=== RUN TestParseSingleRange/unknown_unit904=== PAUSE TestParseSingleRange/unknown_unit905=== RUN TestParseSingleRange/multi-range_ignored906=== PAUSE TestParseSingleRange/multi-range_ignored907=== RUN TestParseSingleRange/malformed_no_dash908=== PAUSE TestParseSingleRange/malformed_no_dash909=== RUN TestParseSingleRange/malformed_both_empty910=== PAUSE TestParseSingleRange/malformed_both_empty911=== RUN TestParseSingleRange/malformed_end_before_start912=== PAUSE TestParseSingleRange/malformed_end_before_start913=== RUN TestParseSingleRange/closed914=== PAUSE TestParseSingleRange/closed915=== RUN TestParseSingleRange/open-ended916=== PAUSE TestParseSingleRange/open-ended917=== RUN TestParseSingleRange/end_clamped_to_size918=== PAUSE TestParseSingleRange/end_clamped_to_size919=== RUN TestParseSingleRange/suffix920=== PAUSE TestParseSingleRange/suffix921=== RUN TestParseSingleRange/suffix_exceeds_size922=== PAUSE TestParseSingleRange/suffix_exceeds_size923=== RUN TestParseSingleRange/single_byte924=== PAUSE TestParseSingleRange/single_byte925=== RUN TestParseSingleRange/start_past_EOF926=== PAUSE TestParseSingleRange/start_past_EOF927=== RUN TestParseSingleRange/start_far_past_EOF928=== PAUSE TestParseSingleRange/start_far_past_EOF929=== CONT TestPresentNotReportedWhileGCDeletesClosure9302026/10/06 11:18:24 INFO Received uploads request method=POST path=/api/pending_closures9312026/10/06 11:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete932--- PASS: TestReadProxyConditionalGet (0.60s)933=== CONT TestPresentReportsOnlyClosureRoots9342026/10/06 11:18:24 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLmUyZGE3OWFlLWJkODMtNDJiZi04YTcwLWRkMGU5Nzg0Mzk1YXgxNzkxMjg1NTA0OTQ2OTcyMjQy9352026/10/06 11:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9362026/10/06 11:18:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLmUyZGE3OWFlLWJkODMtNDJiZi04YTcwLWRkMGU5Nzg0Mzk1YXgxNzkxMjg1NTA0OTQ2OTcyMjQy parts=1937--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.76s)938=== CONT TestCreatePin_ReservedPins939--- PASS: TestReadRedirectNar (0.70s)940=== CONT TestOrphanedObjectsGCStressTest9412026/10/06 11:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34625/oidc942--- PASS: TestReadRedirectKeepsNarinfoProxied (0.73s)943=== CONT TestOrphanedObjectsGC944--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.75s)945=== CONT TestObjectStatsTrigger946--- PASS: TestReadProxyRangeRequest (0.79s)947=== CONT TestPendingCleanupUsesOneCutoff948--- PASS: TestReadProxyDisabled (0.80s)949=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9502026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures9512026/10/06 11:18:25 INFO Received push request method=POST path=/api/pushes9522026/10/06 11:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete953=== RUN TestPush_RejectsBadRequests/no_roots954=== PAUSE TestPush_RejectsBadRequests/no_roots955=== RUN TestPush_RejectsBadRequests/no_objects956=== PAUSE TestPush_RejectsBadRequests/no_objects957=== RUN TestPush_RejectsBadRequests/bad_root958=== PAUSE TestPush_RejectsBadRequests/bad_root959=== RUN TestPush_RejectsBadRequests/root_not_in_objects960=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects961=== CONT TestMultipartCleanup9622026/10/06 11:18:25 INFO Received push request method=POST path=/api/pushes9632026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures9642026/10/06 11:18:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9652026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures9662026/10/06 11:18:25 INFO Aborted multipart uploads count=0 kept=09672026/10/06 11:18:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLjViZTc4ODQxLTIzNDUtNGIyNi05OTdmLTYxYTlhNWUzMzFhZXgxNzkxMjg1NTA0ODExODgxMDUw parts=109682026/10/06 11:18:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9692026/10/06 11:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period9702026/10/06 11:18:25 INFO Completed upload id=19712026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures9732026/10/06 11:18:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9742026/10/06 11:18:25 WARN Found objects in DB but missing from S3, will re-upload count=1975--- PASS: TestService_verifyS3Integrity (1.07s)976=== CONT TestServerTLSConfig977=== RUN TestServerTLSConfig/no_client_CA978=== PAUSE TestServerTLSConfig/no_client_CA979=== RUN TestServerTLSConfig/missing_CA_file980=== PAUSE TestServerTLSConfig/missing_CA_file981=== RUN TestServerTLSConfig/not_a_PEM_file982=== PAUSE TestServerTLSConfig/not_a_PEM_file983=== CONT TestService_NativeMTLS9842026/10/06 11:18:25 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=09852026/10/06 11:18:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete986--- PASS: TestReadProxyInvalidPath (0.64s)987=== CONT TestMetricsInventory9882026/10/06 11:18:25 INFO Vacuumed table table=pending_closures9892026/10/06 11:18:25 INFO Vacuumed table table=pending_objects9902026/10/06 11:18:25 INFO Vacuumed table table=multipart_uploads9912026/10/06 11:18:25 INFO Vacuumed table table=closures9922026/10/06 11:18:25 INFO Vacuumed table table=objects9932026/10/06 11:18:25 INFO Received complete push request method=POST path=/api/pushes/2/complete994--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.08s)995=== CONT TestNARDeduplicationMetadataUploadBug9962026/10/06 11:18:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLjUxNzcxMTVlLTRhMGMtNGE0Zi04NjZiLTRkYTVmMGM5ZTdiN3gxNzkxMjg1NTA0ODM3MzUwMDgy parts=109972026/10/06 11:18:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9982026/10/06 11:18:25 INFO Completed upload id=19992026/10/06 11:18:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010002026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures10012026/10/06 11:18:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures1002--- PASS: TestReadProxyHead (0.68s)1003=== CONT TestCreatePendingClosureRejectsOversizedNAR10042026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures1005--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1006=== CONT TestCacheConfigHandlerMaxNarSize1007--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1008=== CONT TestGenerateLandingPage1009--- PASS: TestGenerateLandingPage (0.00s)1010=== CONT TestService_readinessHandler10112026/10/06 11:18:25 INFO Aborted multipart uploads count=0 kept=010122026/10/06 11:18:25 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=010132026/10/06 11:18:25 INFO Vacuumed table table=pending_closures10142026/10/06 11:18:25 INFO Vacuumed table table=pending_objects10152026/10/06 11:18:25 INFO Vacuumed table table=multipart_uploads10162026/10/06 11:18:25 INFO Vacuumed table table=closures10172026/10/06 11:18:25 INFO Vacuumed table table=objects1018--- PASS: TestReadProxy404 (0.68s)1019=== CONT TestService_healthCheckHandler10202026/10/06 11:18:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001021--- PASS: TestService_createPendingClosureHandler (1.16s)1022=== CONT TestGracefulShutdownDrainsInflight10232026/10/06 11:18:25 INFO Starting HTTP server address=127.0.0.1:4194710242026/10/06 11:18:25 INFO Shutdown signal received, draining in-flight requests timeout=10s1025--- PASS: TestReadProxyNarStreaming (0.67s)1026=== CONT TestGCTaskStore_Fail1027--- PASS: TestGCTaskStore_Fail (0.00s)1028=== CONT TestGCTaskStore_PhaseUpdates1029--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1030=== CONT TestGCTaskStore_CompletedAllowsNewTask1031--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1032=== CONT TestGCTaskStore_GetReturnsLatest1033--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1034=== CONT TestGCTaskStore_GetEmpty1035--- PASS: TestGCTaskStore_GetEmpty (0.00s)1036=== CONT TestGCTaskStore_ConflictDifferentParams1037--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1038=== CONT TestLeadIncumbentAnnouncesAtOnce1039--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.68s)1040=== CONT TestGCTaskStore_StartNew1041--- PASS: TestGCTaskStore_StartNew (0.00s)1042=== CONT TestGCEndsOnShutdown1043=== RUN TestGCEndsOnShutdown/before_the_run1044=== PAUSE TestGCEndsOnShutdown/before_the_run1045=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1046=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1047=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1048=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1049=== CONT TestCommitRacingPendingCleanupKeepsObjects1050--- PASS: TestReadProxyContentNegotiation (0.71s)1051=== CONT TestPushWaitsForSweepHoldingRow1052--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1053=== CONT TestSweepRechecksPendingAfterLocking10542026/10/06 11:18:25 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2110111612/001/proxy.sock10552026/10/06 11:18:25 INFO Starting HTTP server address=127.0.0.1:4410910562026/10/06 11:18:25 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10572026/10/06 11:18:25 INFO Shutdown signal received, draining in-flight requests timeout=10s1058--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.62s)1059=== CONT TestGetExistingObjectsLocksRows1060--- PASS: TestPresentReportsOnlyClosureRoots (0.57s)1061=== CONT TestRegisterCompletedObjectNeedsPendingRow10622026/10/06 11:18:25 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1063--- PASS: TestReadProxyNarinfo (0.75s)1064=== CONT TestSweepSkipsRowsLockedByPush10652026/10/06 11:18:25 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10662026/10/06 11:18:25 WARN Refused reserved pin name=worker-x86_64-linux10672026/10/06 11:18:25 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10682026/10/06 11:18:25 INFO Received create pin request method=POST path=/api/pins/my-app10692026/10/06 11:18:25 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1070--- PASS: TestCreatePin_ReservedPins (0.62s)1071=== CONT TestFailedS3DeleteKeepsTombstone10722026/10/06 11:18:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1073--- PASS: TestObjectStatsTrigger (0.66s)1074=== CONT TestForceGCDuringPushOffersSweptObject1075=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows10762026/10/06 11:18:25 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLjgyNzY4MjY4LWY3YjItNDA5Mi04NTUwLWRhNDQ2YWI3M2MxMngxNzkxMjg1NTA1MTQxMTk1ODc5 parts=121077=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1078=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1079=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1080=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10812026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures10822026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures1083--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.48s)1084=== CONT TestGCSweepDeliversEachKeyOnce10852026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures10862026/10/06 11:18:25 INFO Received cleanup request method=DELETE path=/api/pending_closures10872026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures10882026/10/06 11:18:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1089--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.67s)1090=== CONT TestGCMetrics10912026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/06 11:18:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLjVlMDNlZDVmLTNhODktNGY4Mi1hNmJjLWRkM2RhMTU1ZWY5OHgxNzkxMjg1NTA1MjM2NzM3MDkx parts=1210932026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures10942026/10/06 11:18:25 INFO Received uploads request method=POST path=/api/pending_closures10952026/10/06 11:18:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10962026/10/06 11:18:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1097--- PASS: TestService_NativeMTLS (0.53s)1098=== CONT TestGCBugBareHashReferences1099=== NAME TestNARDeduplicationMetadataUploadBug1100 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1583274630/001/store/k0qymaiskg1i2h5aplnd9lf8r3bd49x4-file1.txt1101--- PASS: TestMetricsInventory (0.60s)1102=== CONT TestGCAdvisoryLockBlocksConcurrentRun11032026/10/06 11:18:25 INFO Received cleanup request method=DELETE path=/api/pending_closures11042026/10/06 11:18:25 WARN readiness check failed error="closed pool"1105--- PASS: TestService_readinessHandler (0.57s)1106=== CONT TestLeadEndsOnShutdown11072026/10/06 11:18:25 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket44/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11082026/10/06 11:18:25 INFO Aborted multipart uploads count=0 kept=111092026/10/06 11:18:25 INFO Received cleanup request method=DELETE path=/api/pending_closures11102026/10/06 11:18:25 INFO Aborted multipart uploads count=1 kept=01111--- PASS: TestMultipartCleanup (0.72s)1112=== CONT TestClientIntegration11132026/10/06 11:18:25 INFO lead: acquired remote=192.0.2.1:123411142026/10/06 11:18:25 INFO lead: released remote=192.0.2.1:12341115--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.55s)1116=== CONT TestLeadElectsOneAndHandsOver1117--- PASS: TestService_healthCheckHandler (0.59s)1118=== CONT TestConnectWaitsForAPeerMigration11192026/10/06 11:18:25 INFO Received push request method=POST path=/api/pushes11202026/10/06 11:18:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11212026/10/06 11:18:25 INFO Uploading k0qymaiskg1i2h5aplnd9lf8r3bd49x4-file1.txt (160B)1122=== NAME TestOrphanedObjectsGC1123 orphaned_objects_gc_test.go:290: GC Test Summary:1124 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1125 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1126 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1127 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1128 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1129--- PASS: TestOrphanedObjectsGC (0.97s)1130=== CONT TestResolveDBConnectionString1131=== RUN TestResolveDBConnectionString/flag_wins1132=== PAUSE TestResolveDBConnectionString/flag_wins1133=== RUN TestResolveDBConnectionString/file_when_flag_empty1134=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1135=== RUN TestResolveDBConnectionString/missing_file_is_an_error1136=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1137=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1138=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1139=== RUN TestResolveDBConnectionString/nothing_configured1140=== PAUSE TestResolveDBConnectionString/nothing_configured1141=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11422026/10/06 11:18:25 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11432026/10/06 11:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11442026/10/06 11:18:25 WARN Failed to register uploaded object key=k0qymaiskg1i2h5aplnd9lf8r3bd49x4.ls error="server returned 404: 404 page not found\n"11452026/10/06 11:18:25 INFO Signed narinfos id=1 count=111462026/10/06 11:18:25 INFO Uploading 1 narinfos11472026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/1/complete11482026/10/06 11:18:26 WARN Failed to register uploaded object key=k0qymaiskg1i2h5aplnd9lf8r3bd49x4.narinfo error="server returned 404: 404 page not found\n"11492026/10/06 11:18:26 INFO Upload complete. (91ms)1150=== NAME TestNARDeduplicationMetadataUploadBug1151 metadata_upload_test.go:54: Retrieved narinfo from S3:1152 StorePath: /build/TestNARDeduplicationMetadataUploadBug1583274630/001/store/k0qymaiskg1i2h5aplnd9lf8r3bd49x4-file1.txt1153 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1154 Compression: zstd1155 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1156 NarSize: 1601157 References: 1158 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1159 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1160 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1161 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1162--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.09s)1163=== CONT TestClientFallsBackToClosures11642026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures11652026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=011662026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period11672026/10/06 11:18:26 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=011682026/10/06 11:18:26 INFO Vacuumed table table=pending_closures11692026/10/06 11:18:26 INFO Vacuumed table table=pending_objects11702026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads11712026/10/06 11:18:26 INFO Vacuumed table table=closures11722026/10/06 11:18:26 INFO Vacuumed table table=objects1173=== NAME TestNARDeduplicationMetadataUploadBug1174 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1583274630/001/store/wn994w9lbyj9xzvfw1rm9p5d6pl01lv4-file2.txt1175--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.64s)1176=== CONT TestClientPushesUseOnePush11772026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=011782026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period11792026/10/06 11:18:26 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=011802026/10/06 11:18:26 INFO Vacuumed table table=pending_closures1181--- PASS: TestGetExistingObjectsLocksRows (0.64s)1182=== CONT TestPinProtectsFromGC11832026/10/06 11:18:26 INFO Vacuumed table table=pending_objects11842026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads11852026/10/06 11:18:26 INFO Vacuumed table table=closures11862026/10/06 11:18:26 INFO Vacuumed table table=objects1187--- PASS: TestSweepRechecksPendingAfterLocking (0.67s)1188=== CONT TestClientSharedPathCommittedMidPush11892026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes1190--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.58s)1191=== CONT TestClientWithDependencies11922026/10/06 11:18:26 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11932026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11942026/10/06 11:18:26 INFO Signed narinfos id=2 count=111952026/10/06 11:18:26 WARN Failed to register uploaded object key=wn994w9lbyj9xzvfw1rm9p5d6pl01lv4.ls error="server returned 404: 404 page not found\n"11962026/10/06 11:18:26 INFO Uploading 1 narinfos11972026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/2/complete11982026/10/06 11:18:26 WARN Failed to register uploaded object key=wn994w9lbyj9xzvfw1rm9p5d6pl01lv4.narinfo error="server returned 404: 404 page not found\n"11992026/10/06 11:18:26 INFO Upload complete. (56ms)1200=== NAME TestNARDeduplicationMetadataUploadBug1201 metadata_upload_test.go:76: Retrieved narinfo from S3:1202 StorePath: /build/TestNARDeduplicationMetadataUploadBug1583274630/001/store/wn994w9lbyj9xzvfw1rm9p5d6pl01lv4-file2.txt1203 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1204 Compression: zstd1205 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1206 NarSize: 1601207 References: 1208 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1209 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1210 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1211 {"version":1,"root":{"type":"regular","size":44}}1212--- PASS: TestNARDeduplicationMetadataUploadBug (0.85s)1213=== CONT TestClientMultipleUploads12142026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=012152026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures12162026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period12172026/10/06 11:18:26 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=012182026/10/06 11:18:26 INFO Vacuumed table table=pending_closures12192026/10/06 11:18:26 INFO Vacuumed table table=pending_objects12202026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads12212026/10/06 11:18:26 INFO Vacuumed table table=closures12222026/10/06 11:18:26 INFO Vacuumed table table=objects12232026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=012242026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period12252026/10/06 11:18:26 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=012262026/10/06 11:18:26 INFO Vacuumed table table=pending_closures12272026/10/06 11:18:26 INFO Vacuumed table table=pending_objects12282026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads12292026/10/06 11:18:26 INFO Vacuumed table table=closures12302026/10/06 11:18:26 INFO Vacuumed table table=objects1231--- PASS: TestSweepSkipsRowsLockedByPush (0.66s)1232=== CONT TestGCSweepSkipsPendingObjects12332026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=012342026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures12352026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period12362026/10/06 11:18:26 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=012372026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=012382026/10/06 11:18:26 INFO Vacuumed table table=pending_closures12392026/10/06 11:18:26 INFO Vacuumed table table=pending_objects12402026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads12412026/10/06 11:18:26 INFO Vacuumed table table=closures12422026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period12432026/10/06 11:18:26 INFO Vacuumed table table=objects1244--- PASS: TestGCSweepDeliversEachKeyOnce (0.57s)1245=== CONT TestPushDedupSurvivesConcurrentGC12462026/10/06 11:18:26 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12472026/10/06 11:18:26 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1248--- PASS: TestFailedS3DeleteKeepsTombstone (0.68s)1249=== CONT TestTombstonedObjectOfferedWithoutWaiting12502026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=012512026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period12522026/10/06 11:18:26 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=012532026/10/06 11:18:26 INFO Vacuumed table table=pending_closures12542026/10/06 11:18:26 INFO Vacuumed table table=pending_objects12552026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads12562026/10/06 11:18:26 INFO Vacuumed table table=closures12572026/10/06 11:18:26 INFO Vacuumed table table=objects1258--- PASS: TestGCMetrics (0.55s)1259=== CONT TestService_ReadScope_PublicByDefault12602026/10/06 11:18:26 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"1261--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.47s)1262=== CONT TestDeduplicatedObjectsRecordedAsPending12632026/10/06 11:18:26 INFO lead: acquired remote=192.0.2.1:123412642026/10/06 11:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12652026/10/06 11:18:26 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLjUzNmJhM2U4LWQ3NmItNGExOC1hMWVjLTEyNzk0NjdmODBhN3gxNzkxMjg1NTA1ODEyMTQ3OTE0 error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12662026/10/06 11:18:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2ZjNjkyY2YtZjE4OS00OTQ4LTgzMzktMjJkNGRhMmY5YjgyLjRmNDkwZjVkLTRiMGMtNGYzMS1hMTNkLWQxZWI4YmIxZDVjYXgxNzkxMjg1NTA1ODAzNTQzMDcz parts=1212672026/10/06 11:18:26 INFO Received cleanup request method=DELETE path=/api/pending_closures12682026/10/06 11:18:26 INFO Aborted multipart uploads count=1 kept=01269--- PASS: TestRedundantMultipartUpload (2.20s)1270=== CONT TestClientErrorHandling1271=== RUN TestClientErrorHandling/InvalidStorePath1272=== PAUSE TestClientErrorHandling/InvalidStorePath1273=== RUN TestClientErrorHandling/InvalidAuthToken1274=== PAUSE TestClientErrorHandling/InvalidAuthToken1275=== RUN TestClientErrorHandling/ServerNotAvailable1276=== PAUSE TestClientErrorHandling/ServerNotAvailable1277=== CONT TestCacheStatsHandler12782026/10/06 11:18:26 INFO lead: acquired remote=192.0.2.1:12341279=== NAME TestClientIntegration1280 client_integration_test.go:286: Created store path: /build/TestClientIntegration3745835646/002/store/s4m64s8ghnfq1kb8mi3mbdrgpzg6vdwd-test-file.txt1281--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.76s)1282=== CONT TestCacheConfigHandler1283=== RUN TestCacheConfigHandler/full_config,_no_issuer1284=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1285=== RUN TestCacheConfigHandler/no_cache_url_configured1286=== PAUSE TestCacheConfigHandler/no_cache_url_configured1287=== RUN TestCacheConfigHandler/no_signing_keys1288=== PAUSE TestCacheConfigHandler/no_signing_keys1289=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1290=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1291=== CONT TestService_ReadAuthMiddleware12922026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes12932026/10/06 11:18:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12942026/10/06 11:18:26 INFO Uploading s4m64s8ghnfq1kb8mi3mbdrgpzg6vdwd-test-file.txt (152B)1295--- PASS: TestPushWaitsForSweepHoldingRow (1.10s)1296=== CONT TestClientCADerivations12972026/10/06 11:18:26 WARN Failed to register uploaded object key=s4m64s8ghnfq1kb8mi3mbdrgpzg6vdwd.ls error="server returned 404: 404 page not found\n"12982026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12992026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13002026/10/06 11:18:26 INFO Signed narinfos id=1 count=113012026/10/06 11:18:26 INFO Uploading 1 narinfos13022026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/1/complete13032026/10/06 11:18:26 WARN Failed to register uploaded object key=s4m64s8ghnfq1kb8mi3mbdrgpzg6vdwd.narinfo error="server returned 404: 404 page not found\n"1304--- PASS: TestGCBugBareHashReferences (0.74s)1305=== CONT TestService_RequireScope_OIDC13062026/10/06 11:18:26 INFO Upload complete. (70ms)13072026/10/06 11:18:26 INFO All 1 paths already cached1308=== NAME TestClientIntegration1309 client_integration_test.go:312: Retrieved narinfo from S3:1310 StorePath: /build/TestClientIntegration3745835646/002/store/s4m64s8ghnfq1kb8mi3mbdrgpzg6vdwd-test-file.txt1311 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1312 Compression: zstd1313 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11314 NarSize: 1521315 References: 1316 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11317 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1318 client_integration_test.go:313: Decompressed .ls content (64 bytes):1319 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1320 client_integration_test.go:316: Testing garbage collection...13212026/10/06 11:18:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures13222026/10/06 11:18:26 INFO Garbage collection started13232026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=013242026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period13252026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures13262026/10/06 11:18:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43789/oidc13272026/10/06 11:18:26 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=01328=== NAME TestPinProtectsFromGC1329 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC633308659/001/store/7c1pv6b0p8vh5k0kcv9n96vxjajrn5yh-pinned-file.txt1330 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC633308659/001/store/hmkam4rmry2jdiz7gvc7gfapk4ds981l-unpinned-file.txt13312026/10/06 11:18:26 INFO Vacuumed table table=pending_closures13322026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=013332026/10/06 11:18:26 INFO Vacuumed table table=pending_objects13342026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period13352026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads13362026/10/06 11:18:26 INFO Vacuumed table table=closures13372026/10/06 11:18:26 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=013382026/10/06 11:18:26 INFO Vacuumed table table=objects13392026/10/06 11:18:26 INFO Vacuumed table table=pending_closures13402026/10/06 11:18:26 INFO Vacuumed table table=pending_objects13412026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads13422026/10/06 11:18:26 INFO Vacuumed table table=closures13432026/10/06 11:18:26 INFO Vacuumed table table=objects1344=== NAME TestClientMultipleUploads1345 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads577532682/001/store/ls2yjbcgk628ggimdhp2zkpz2hlk8rgl-test-file-0.txt1346--- PASS: TestGCSweepSkipsPendingObjects (0.45s)1347=== CONT TestService_AuthMiddleware_OIDC13482026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures13492026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures13502026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures13512026/10/06 11:18:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1352=== NAME TestClientWithDependencies13532026/10/06 11:18:26 INFO Uploading mji4iada49a1dppxjq0y71hg451dkjck-b (216B)1354 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3915228532/001/store/mcx2jbnm6ff3znlsc3kmbfwrk6all11v-test-script13552026/10/06 11:18:26 INFO Uploading rqa4x01xnc7xgx0ghvn43v8igk87cr6v-shared-dep (136B)13562026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes13572026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes13582026/10/06 11:18:26 WARN Failed to register uploaded object key=fhkb8k5mbfymn637h7045mxd17glmsbf.ls error="server returned 404: 404 page not found\n"13592026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/0nlxa02vlwfarl89ik0r6d3qxcrn8bzsjgxpmg55165w2g62mffw.nar.zst error="server returned 404: 404 page not found\n"13602026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures13612026/10/06 11:18:26 WARN Failed to register uploaded object key=mji4iada49a1dppxjq0y71hg451dkjck.ls error="server returned 404: 404 page not found\n"13622026/10/06 11:18:26 WARN Failed to register uploaded object key=rqa4x01xnc7xgx0ghvn43v8igk87cr6v.ls error="server returned 404: 404 page not found\n"13632026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13642026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13652026/10/06 11:18:26 INFO Signed narinfos id=1 count=213662026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13672026/10/06 11:18:26 INFO Signed narinfos id=2 count=213682026/10/06 11:18:26 INFO Uploading 4 narinfos13692026/10/06 11:18:26 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13702026/10/06 11:18:26 INFO Uploading 5bkbh61y14qad02xycdnrj51587kr8bb-shared-dep (136B)13712026/10/06 11:18:26 INFO Uploading w5ha6g9j7bias6f95w464sxz9q10y2d0-top (224B)1372--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.40s)1373=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13742026/10/06 11:18:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13752026/10/06 11:18:26 INFO Uploading z45p0znskxpzkm8pg5b91nzrq61psqac-b (216B)13762026/10/06 11:18:26 INFO Uploading gch7yl1x722hc030qqvqs43ak8v41nr9-shared-dep (136B)13772026/10/06 11:18:26 WARN Failed to register uploaded object key=mji4iada49a1dppxjq0y71hg451dkjck.narinfo error="server returned 404: 404 page not found\n"13782026/10/06 11:18:26 WARN Failed to register uploaded object key=fhkb8k5mbfymn637h7045mxd17glmsbf.narinfo error="server returned 404: 404 page not found\n"13792026/10/06 11:18:26 WARN Failed to register uploaded object key=rqa4x01xnc7xgx0ghvn43v8igk87cr6v.narinfo error="server returned 404: 404 page not found\n"1380=== NAME TestClientMultipleUploads1381 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads577532682/001/store/jqillknxfwf3ijy8dz4cd767k8kscly8-test-file-1.txt13822026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13832026/10/06 11:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13842026/10/06 11:18:26 WARN Failed to register uploaded object key=rqa4x01xnc7xgx0ghvn43v8igk87cr6v.narinfo error="server returned 404: 404 page not found\n"13852026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/00hvw2pf4sqm18zc8xnw0divrm7f8jxvfh8nlb8siamw7abiz78q.nar.zst error="server returned 404: 404 page not found\n"13862026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13872026/10/06 11:18:26 WARN Failed to register uploaded object key=gch7yl1x722hc030qqvqs43ak8v41nr9.ls error="server returned 404: 404 page not found\n"13882026/10/06 11:18:26 WARN Failed to register uploaded object key=5bkbh61y14qad02xycdnrj51587kr8bb.ls error="server returned 404: 404 page not found\n"13892026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/14gkyn86g4xfx2qjngc8if8dfkjc3ip90a07d33gf2qjc452r44x.nar.zst error="server returned 404: 404 page not found\n"13902026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13912026/10/06 11:18:26 INFO Signed narinfos id=1 count=213922026/10/06 11:18:26 WARN Failed to register uploaded object key=z45p0znskxpzkm8pg5b91nzrq61psqac.ls error="server returned 404: 404 page not found\n"13932026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13942026/10/06 11:18:26 WARN Failed to register uploaded object key=a2jnnww737gvk8snbw289i4prxgxq8vp.ls error="server returned 404: 404 page not found\n"13952026/10/06 11:18:26 WARN Failed to register uploaded object key=w5ha6g9j7bias6f95w464sxz9q10y2d0.ls error="server returned 404: 404 page not found\n"13962026/10/06 11:18:26 INFO Uploading 2 narinfos13972026/10/06 11:18:26 INFO Signed narinfos id=1 count=313982026/10/06 11:18:26 INFO Uploading 3 narinfos13992026/10/06 11:18:26 WARN Failed to register uploaded object key=w5ha6g9j7bias6f95w464sxz9q10y2d0.narinfo error="server returned 404: 404 page not found\n"14002026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/1/complete14012026/10/06 11:18:26 WARN Failed to register uploaded object key=5bkbh61y14qad02xycdnrj51587kr8bb.narinfo error="server returned 404: 404 page not found\n"14022026/10/06 11:18:26 WARN Failed to register uploaded object key=gch7yl1x722hc030qqvqs43ak8v41nr9.narinfo error="server returned 404: 404 page not found\n"14032026/10/06 11:18:26 WARN Failed to register uploaded object key=a2jnnww737gvk8snbw289i4prxgxq8vp.narinfo error="server returned 404: 404 page not found\n"14042026/10/06 11:18:26 INFO Completed upload id=114052026/10/06 11:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14062026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/1/complete14072026/10/06 11:18:26 WARN Failed to register uploaded object key=z45p0znskxpzkm8pg5b91nzrq61psqac.narinfo error="server returned 404: 404 page not found\n"14082026/10/06 11:18:26 INFO Completed upload id=214092026/10/06 11:18:26 INFO Upload complete. (82ms)1410=== NAME TestClientFallsBackToClosures1411 client_pushes_test.go:112: Retrieved narinfo from S3:1412 StorePath: /build/TestClientFallsBackToClosures2187969249/001/store/rqa4x01xnc7xgx0ghvn43v8igk87cr6v-shared-dep1413 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1414 Compression: zstd1415 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821416 NarSize: 1361417 References: 1418 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1419--- PASS: TestService_ReadScope_PublicByDefault (0.40s)1420=== CONT TestService_AuthMiddleware_MTLSProxyHeader14212026/10/06 11:18:26 INFO Upload complete. (63ms)1422=== NAME TestClientFallsBackToClosures1423 client_pushes_test.go:112: Retrieved narinfo from S3:1424 StorePath: /build/TestClientFallsBackToClosures2187969249/001/store/fhkb8k5mbfymn637h7045mxd17glmsbf-a1425 URL: nar/0nlxa02vlwfarl89ik0r6d3qxcrn8bzsjgxpmg55165w2g62mffw.nar.zst1426 Compression: zstd1427 NarHash: sha256:0nlxa02vlwfarl89ik0r6d3qxcrn8bzsjgxpmg55165w2g62mffw1428 NarSize: 2161429 References: /build/TestClientFallsBackToClosures2187969249/001/store/rqa4x01xnc7xgx0ghvn43v8igk87cr6v-shared-dep1430 CA: text:sha256:10b2rc4plkkspf0gz7svcdwkxxdj0ymkhp4mbfr0g48mkwd6xm291431=== NAME TestClientSharedPathCommittedMidPush1432 client_integration_test.go:680: Retrieved narinfo from S3:1433 StorePath: /build/TestClientSharedPathCommittedMidPush3502097541/001/store/5bkbh61y14qad02xycdnrj51587kr8bb-shared-dep1434 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1435 Compression: zstd1436 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821437 NarSize: 13614382026/10/06 11:18:26 INFO Upload complete. (63ms)1439 References: 1440 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1441=== NAME TestClientWithDependencies1442 client_integration_test.go:615: Found 1 dependencies (including self)1443=== NAME TestClientPushesUseOnePush1444 client_pushes_test.go:97: Retrieved narinfo from S3:1445 StorePath: /build/TestClientPushesUseOnePush1353951979/001/store/gch7yl1x722hc030qqvqs43ak8v41nr9-shared-dep1446 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1447 Compression: zstd1448 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821449 NarSize: 1361450 References: 1451 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1452=== NAME TestClientFallsBackToClosures1453 client_pushes_test.go:112: Retrieved narinfo from S3:1454 StorePath: /build/TestClientFallsBackToClosures2187969249/001/store/mji4iada49a1dppxjq0y71hg451dkjck-b1455 URL: nar/0nlxa02vlwfarl89ik0r6d3qxcrn8bzsjgxpmg55165w2g62mffw.nar.zst1456 Compression: zstd1457 NarHash: sha256:0nlxa02vlwfarl89ik0r6d3qxcrn8bzsjgxpmg55165w2g62mffw1458 NarSize: 2161459 References: /build/TestClientFallsBackToClosures2187969249/001/store/rqa4x01xnc7xgx0ghvn43v8igk87cr6v-shared-dep1460 CA: text:sha256:10b2rc4plkkspf0gz7svcdwkxxdj0ymkhp4mbfr0g48mkwd6xm291461=== NAME TestClientSharedPathCommittedMidPush1462 client_integration_test.go:680: Retrieved narinfo from S3:1463 StorePath: /build/TestClientSharedPathCommittedMidPush3502097541/001/store/w5ha6g9j7bias6f95w464sxz9q10y2d0-top1464 URL: nar/00hvw2pf4sqm18zc8xnw0divrm7f8jxvfh8nlb8siamw7abiz78q.nar.zst1465 Compression: zstd1466 NarHash: sha256:00hvw2pf4sqm18zc8xnw0divrm7f8jxvfh8nlb8siamw7abiz78q1467 NarSize: 2241468 References: /build/TestClientSharedPathCommittedMidPush3502097541/001/store/5bkbh61y14qad02xycdnrj51587kr8bb-shared-dep1469 CA: text:sha256:0caq8m5ypzbyahk6hbc27jqwxjqzcz9yf5f6a1f10l0qnc368fil1470=== NAME TestClientPushesUseOnePush1471 client_pushes_test.go:97: Retrieved narinfo from S3:1472 StorePath: /build/TestClientPushesUseOnePush1353951979/001/store/a2jnnww737gvk8snbw289i4prxgxq8vp-a1473 URL: nar/14gkyn86g4xfx2qjngc8if8dfkjc3ip90a07d33gf2qjc452r44x.nar.zst1474 Compression: zstd1475 NarHash: sha256:14gkyn86g4xfx2qjngc8if8dfkjc3ip90a07d33gf2qjc452r44x1476 NarSize: 2161477 References: /build/TestClientPushesUseOnePush1353951979/001/store/gch7yl1x722hc030qqvqs43ak8v41nr9-shared-dep1478 CA: text:sha256:06hh5ijq39h7nc6nb6dc6y8c39y98rgk13nzqqarz0dyj56f263514792026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes1480 client_pushes_test.go:97: Retrieved narinfo from S3:1481 StorePath: /build/TestClientPushesUseOnePush1353951979/001/store/z45p0znskxpzkm8pg5b91nzrq61psqac-b1482 URL: nar/14gkyn86g4xfx2qjngc8if8dfkjc3ip90a07d33gf2qjc452r44x.nar.zst1483 Compression: zstd1484 NarHash: sha256:14gkyn86g4xfx2qjngc8if8dfkjc3ip90a07d33gf2qjc452r44x1485 NarSize: 2161486 References: /build/TestClientPushesUseOnePush1353951979/001/store/gch7yl1x722hc030qqvqs43ak8v41nr9-shared-dep1487 CA: text:sha256:06hh5ijq39h7nc6nb6dc6y8c39y98rgk13nzqqarz0dyj56f26351488--- PASS: TestClientFallsBackToClosures (0.69s)1489=== CONT TestPendingClosureWriteTimeout/empty1490=== CONT TestPendingClosureWriteTimeout/670k_objects1491=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1492--- PASS: TestClientSharedPathCommittedMidPush (0.61s)1493=== CONT TestPendingClosureWriteTimeout/400_objects1494=== CONT TestProxyWriteTimeout/narinfo1495=== CONT TestProxyWriteTimeout/10_GiB_nar1496=== CONT TestProxyWriteTimeout/unknown_size1497=== CONT TestProxyWriteTimeout/1_GiB_nar1498--- PASS: TestProxyWriteTimeout (0.08s)1499 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1500 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1501 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1502 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1503=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15042026/10/06 11:18:26 INFO Received uploads request method=POST path=/1505=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15062026/10/06 11:18:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15072026/10/06 11:18:26 INFO Uploading 7c1pv6b0p8vh5k0kcv9n96vxjajrn5yh-pinned-file.txt (128B)15082026/10/06 11:18:26 INFO Received request for more parts method=POST path=/1509=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15102026/10/06 11:18:26 INFO Received complete multipart upload request method=POST path=/1511=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15122026/10/06 11:18:26 INFO Received uploads request method=POST path=/1513--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1514 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1515 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1516 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1517 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1518=== CONT TestIsValidUploadKey/narinfo1519=== CONT TestIsValidUploadKey/realisation_plus_in_output1520=== CONT TestIsValidUploadKey/unknown_type1521=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1522=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1523=== CONT TestIsValidUploadKey/index.html1524=== CONT TestIsValidUploadKey/nix-cache-info1525=== CONT TestIsValidUploadKey/build_log_home-manager_file1526=== CONT TestIsValidUploadKey/realisation1527=== CONT TestIsValidUploadKey/build_log_equals1528=== CONT TestIsValidUploadKey/build_log_question_mark1529=== CONT TestIsValidUploadKey/build_log_plus_in_name1530=== CONT TestIsValidUploadKey/absolute1531=== CONT TestIsValidUploadKey/empty_key1532=== CONT TestIsValidUploadKey/traversal_nar1533=== CONT TestIsValidUploadKey/nar_plain1534=== CONT TestIsValidUploadKey/build_log1535=== CONT TestIsValidUploadKey/listing1536=== CONT TestIsValidUploadKey/traversal1537=== CONT TestIsValidUploadKey/nar_xz1538=== CONT TestIsValidUploadKey/nar_zst1539=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1540--- PASS: TestIsValidUploadKey (0.09s)1541 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1542 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1543 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1544 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1545 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1546 --- PASS: TestIsValidUploadKey/index.html (0.00s)1547 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1548 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1549 --- PASS: TestIsValidUploadKey/realisation (0.00s)1550 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1551 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1552 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1553 --- PASS: TestIsValidUploadKey/absolute (0.00s)1554 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1555 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1556 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1557 --- PASS: TestIsValidUploadKey/build_log (0.00s)1558 --- PASS: TestIsValidUploadKey/listing (0.00s)1559 --- PASS: TestIsValidUploadKey/traversal (0.00s)1560 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1561 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1562 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1563=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15642026/10/06 11:18:26 INFO Received uploads request method=POST path=/1565--- PASS: TestClientPushesUseOnePush (0.67s)1566=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15672026/10/06 11:18:26 INFO Received request for more parts method=POST path=/1568--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.74s)1569=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15702026/10/06 11:18:26 INFO Received complete multipart upload request method=POST path=/15712026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15722026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15732026/10/06 11:18:26 WARN Failed to register uploaded object key=7c1pv6b0p8vh5k0kcv9n96vxjajrn5yh.ls error="server returned 404: 404 page not found\n"15742026/10/06 11:18:26 INFO Signed narinfos id=1 count=115752026/10/06 11:18:26 INFO Uploading 1 narinfos1576=== NAME TestClientMultipleUploads1577 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads577532682/001/store/49gfpqcchi0m9ib9qcsnhqvkhby5m6nh-test-file-2.txt15782026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/1/complete15792026/10/06 11:18:26 WARN Failed to register uploaded object key=7c1pv6b0p8vh5k0kcv9n96vxjajrn5yh.narinfo error="server returned 404: 404 page not found\n"15802026/10/06 11:18:26 INFO Upload complete. (54ms)15812026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures15822026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=01583--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.39s)1584=== CONT TestIsValidCachePath/narinfo1585=== CONT TestIsValidCachePath/index.html1586=== CONT TestIsValidCachePath/short_hash1587=== CONT TestIsValidCachePath/wrong_extension1588=== CONT TestIsValidCachePath/leading_slash1589=== CONT TestIsValidCachePath/empty1590=== CONT TestIsValidCachePath/random_path1591=== CONT TestIsValidCachePath/invalid_char_u1592=== CONT TestIsValidCachePath/invalid_char_e1593=== CONT TestIsValidCachePath/traversal_in_middle1594=== CONT TestIsValidCachePath/traversal_parent1595=== CONT TestIsValidCachePath/nar_xz1596=== CONT TestIsValidCachePath/nar_uncompressed1597=== CONT TestIsValidCachePath/nar_bz21598=== CONT TestIsValidCachePath/nix-cache-info1599=== CONT TestIsValidCachePath/log1600=== CONT TestIsValidCachePath/ls1601=== CONT TestIsValidCachePath/realisation1602=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1603=== CONT TestIsValidCachePath/nar_zst1604=== CONT TestParseSingleRange/none1605--- PASS: TestIsValidCachePath (0.00s)1606 --- PASS: TestIsValidCachePath/narinfo (0.00s)1607 --- PASS: TestIsValidCachePath/index.html (0.00s)1608 --- PASS: TestIsValidCachePath/short_hash (0.00s)1609 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1610 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1611 --- PASS: TestIsValidCachePath/empty (0.00s)1612 --- PASS: TestIsValidCachePath/random_path (0.00s)1613 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1614 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1615 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1616 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1617 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1618 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1619 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1620 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1621 --- PASS: TestIsValidCachePath/log (0.00s)1622 --- PASS: TestIsValidCachePath/ls (0.00s)1623 --- PASS: TestIsValidCachePath/realisation (0.00s)1624 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1625 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1626=== CONT TestParseSingleRange/open-ended1627=== CONT TestParseSingleRange/malformed_both_empty1628=== CONT TestParseSingleRange/start_far_past_EOF1629=== CONT TestParseSingleRange/closed1630=== CONT TestParseSingleRange/start_past_EOF1631=== CONT TestParseSingleRange/malformed_end_before_start1632=== CONT TestParseSingleRange/single_byte1633=== CONT TestParseSingleRange/suffix_exceeds_size1634=== CONT TestParseSingleRange/suffix1635=== CONT TestParseSingleRange/multi-range_ignored1636=== CONT TestParseSingleRange/end_clamped_to_size1637=== CONT TestParseSingleRange/malformed_no_dash1638=== CONT TestParseSingleRange/unknown_unit1639--- PASS: TestParseSingleRange (0.00s)1640 --- PASS: TestParseSingleRange/none (0.00s)1641 --- PASS: TestParseSingleRange/open-ended (0.00s)1642 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1643 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1644 --- PASS: TestParseSingleRange/closed (0.00s)1645 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1646 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1647 --- PASS: TestParseSingleRange/single_byte (0.00s)1648 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1649 --- PASS: TestParseSingleRange/suffix (0.00s)1650 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1651 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1652 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1653 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1654=== CONT TestPush_RejectsBadRequests/no_roots16552026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes1656=== CONT TestPush_RejectsBadRequests/bad_root16572026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes1658=== CONT TestPush_RejectsBadRequests/root_not_in_objects16592026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes1660=== CONT TestPush_RejectsBadRequests/no_objects16612026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes1662=== CONT TestServerTLSConfig/no_client_CA1663=== CONT TestServerTLSConfig/not_a_PEM_file1664--- PASS: TestPush_RejectsBadRequests (0.96s)1665 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1666 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1667 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1668 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1669=== CONT TestServerTLSConfig/missing_CA_file1670--- PASS: TestServerTLSConfig (0.00s)1671 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1672 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1673 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1674=== CONT TestGCEndsOnShutdown/before_the_run16752026/10/06 11:18:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46061/oidc16762026/10/06 11:18:26 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=016772026/10/06 11:18:26 INFO Vacuumed table table=pending_closures1678--- PASS: TestCacheStatsHandler (0.35s)1679=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16802026/10/06 11:18:26 INFO Vacuumed table table=pending_objects16812026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads16822026/10/06 11:18:26 INFO Vacuumed table table=closures16832026/10/06 11:18:26 INFO Vacuumed table table=objects1684--- PASS: TestService_ReadAuthMiddleware (0.33s)1685=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16862026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes16872026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=016882026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period16892026/10/06 11:18:26 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=016902026/10/06 11:18:26 INFO Vacuumed table table=pending_closures16912026/10/06 11:18:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16922026/10/06 11:18:26 INFO Uploading mcx2jbnm6ff3znlsc3kmbfwrk6all11v-test-script (136B)16932026/10/06 11:18:26 INFO Vacuumed table table=pending_objects16942026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads16952026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16962026/10/06 11:18:26 WARN Failed to register uploaded object key=log/xs4d788nkrlng23hbkpkqzs7ayawg151-test-script.drv error="server returned 404: 404 page not found\n"1697=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16982026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16992026/10/06 11:18:26 INFO Vacuumed table table=closures17002026/10/06 11:18:26 WARN Failed to register uploaded object key=mcx2jbnm6ff3znlsc3kmbfwrk6all11v.ls error="server returned 404: 404 page not found\n"17012026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes17022026/10/06 11:18:26 INFO Signed narinfos id=1 count=117032026/10/06 11:18:26 INFO Uploading 1 narinfos17042026/10/06 11:18:26 INFO Received push request method=POST path=/api/pushes17052026/10/06 11:18:26 INFO Vacuumed table table=objects1706--- PASS: TestPushDedupSurvivesConcurrentGC (0.53s)1707=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17082026/10/06 11:18:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17092026/10/06 11:18:26 INFO Uploading hmkam4rmry2jdiz7gvc7gfapk4ds981l-unpinned-file.txt (128B)1710=== CONT TestResolveDBConnectionString/flag_wins17112026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/1/complete1712=== CONT TestResolveDBConnectionString/PGHOST_allows_empty17132026/10/06 11:18:26 WARN Failed to register uploaded object key=mcx2jbnm6ff3znlsc3kmbfwrk6all11v.narinfo error="server returned 404: 404 page not found\n"1714=== CONT TestResolveDBConnectionString/nothing_configured1715=== CONT TestResolveDBConnectionString/missing_file_is_an_error1716=== CONT TestResolveDBConnectionString/file_when_flag_empty1717=== CONT TestClientErrorHandling/InvalidStorePath1718--- PASS: TestResolveDBConnectionString (0.00s)1719 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1720 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1721 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1722 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1723 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17242026/10/06 11:18:26 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17252026/10/06 11:18:26 INFO Uploading ls2yjbcgk628ggimdhp2zkpz2hlk8rgl-test-file-0.txt (160B)17262026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17272026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17282026/10/06 11:18:26 WARN Failed to register uploaded object key=hmkam4rmry2jdiz7gvc7gfapk4ds981l.ls error="server returned 404: 404 page not found\n"17292026/10/06 11:18:26 INFO Signed narinfos id=2 count=117302026/10/06 11:18:26 INFO Uploading jqillknxfwf3ijy8dz4cd767k8kscly8-test-file-1.txt (160B)17312026/10/06 11:18:26 INFO Uploading 49gfpqcchi0m9ib9qcsnhqvkhby5m6nh-test-file-2.txt (160B)17322026/10/06 11:18:26 INFO Uploading 1 narinfos17332026/10/06 11:18:26 WARN Failed to register uploaded object key=ls2yjbcgk628ggimdhp2zkpz2hlk8rgl.ls error="server returned 404: 404 page not found\n"17342026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/2/complete17352026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17362026/10/06 11:18:26 WARN Failed to register uploaded object key=hmkam4rmry2jdiz7gvc7gfapk4ds981l.narinfo error="server returned 404: 404 page not found\n"17372026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17382026/10/06 11:18:26 WARN Failed to register uploaded object key=jqillknxfwf3ijy8dz4cd767k8kscly8.ls error="server returned 404: 404 page not found\n"17392026/10/06 11:18:26 WARN Failed to register uploaded object key=49gfpqcchi0m9ib9qcsnhqvkhby5m6nh.ls error="server returned 404: 404 page not found\n"17402026/10/06 11:18:26 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17412026/10/06 11:18:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17422026/10/06 11:18:26 INFO Signed narinfos id=1 count=317432026/10/06 11:18:26 INFO Uploading 3 narinfos17442026/10/06 11:18:26 WARN Failed to register uploaded object key=ls2yjbcgk628ggimdhp2zkpz2hlk8rgl.narinfo error="server returned 404: 404 page not found\n"17452026/10/06 11:18:26 WARN Failed to register uploaded object key=49gfpqcchi0m9ib9qcsnhqvkhby5m6nh.narinfo error="server returned 404: 404 page not found\n"17462026/10/06 11:18:26 INFO Received complete push request method=POST path=/api/pushes/1/complete17472026/10/06 11:18:26 WARN Failed to register uploaded object key=jqillknxfwf3ijy8dz4cd767k8kscly8.narinfo error="server returned 404: 404 page not found\n"17482026/10/06 11:18:26 INFO Upload complete. (65ms)17492026/10/06 11:18:26 INFO Upload complete. (88ms)17502026/10/06 11:18:26 INFO Upload complete. (73ms)1751=== NAME TestClientMultipleUploads1752 client_integration_test.go:369: Uploaded 3 paths in 107.592886ms1753=== NAME TestClientWithDependencies1754 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3915228532/001/store) requires matching store prefix1755--- PASS: TestClientWithDependencies (0.72s)1756=== CONT TestClientErrorHandling/ServerNotAvailable1757--- PASS: TestClientMultipleUploads (0.69s)1758=== CONT TestClientErrorHandling/InvalidAuthToken1759=== RUN TestService_RequireScope_OIDC/builder_may_write1760=== PAUSE TestService_RequireScope_OIDC/builder_may_write1761=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1762=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1763=== RUN TestService_RequireScope_OIDC/ops_may_admin1764=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1765=== RUN TestService_RequireScope_OIDC/ops_may_not_write1766=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1767=== RUN TestService_RequireScope_OIDC/reader_may_not_write1768=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1769=== RUN TestService_RequireScope_OIDC/static_token_may_admin1770=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1771=== RUN TestService_RequireScope_OIDC/static_token_may_write1772=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1773=== RUN TestService_RequireScope_OIDC/reader_may_read1774=== PAUSE TestService_RequireScope_OIDC/reader_may_read1775=== RUN TestService_RequireScope_OIDC/writer_implies_read1776=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1777=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1778=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1779=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1780=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1781=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1782=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1783=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1784=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1785=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1786=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1787=== CONT TestCacheConfigHandler/full_config,_no_issuer1788=== CONT TestCacheConfigHandler/no_signing_keys1789=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1790=== CONT TestCacheConfigHandler/no_cache_url_configured1791--- PASS: TestCacheConfigHandler (0.00s)1792 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1793 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1794 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1795 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1796=== CONT TestService_RequireScope_OIDC/builder_may_write1797=== CONT TestService_RequireScope_OIDC/reader_may_read1798=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1799=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18002026/10/06 11:18:26 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1801=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1802=== CONT TestService_RequireScope_OIDC/reader_may_not_write1803=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1804=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1805=== CONT TestService_RequireScope_OIDC/static_token_may_write1806=== CONT TestService_RequireScope_OIDC/static_token_may_admin1807=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1808=== CONT TestService_RequireScope_OIDC/ops_may_admin1809=== CONT TestService_RequireScope_OIDC/ops_may_not_write1810=== CONT TestService_RequireScope_OIDC/writer_implies_read1811--- PASS: TestService_RequireScope_OIDC (0.31s)1812 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1813 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1814 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1815 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1816 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1817 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1818 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1819 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1820 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1821 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1823 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1825 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)18262026/10/06 11:18:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures18272026/10/06 11:18:26 INFO Garbage collection started18282026/10/06 11:18:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18292026/10/06 11:18:26 WARN mTLS auth: bound subjects configured but subject DN unavailable18302026/10/06 11:18:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1831--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.19s)18322026/10/06 11:18:26 INFO Aborted multipart uploads count=0 kept=018332026/10/06 11:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period1834=== NAME TestClientCADerivations1835 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3800425586/001/store/zsam02xbc8gkddy2pp9b75d96ihpss3d-ca-test18362026/10/06 11:18:26 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=018372026/10/06 11:18:26 INFO Vacuumed table table=pending_closures18382026/10/06 11:18:26 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/present18392026/10/06 11:18:26 INFO Vacuumed table table=pending_objects18402026/10/06 11:18:26 INFO Vacuumed table table=multipart_uploads1841--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.22s)18422026/10/06 11:18:26 INFO Vacuumed table table=closures18432026/10/06 11:18:26 INFO Vacuumed table table=objects1844=== NAME TestClientCADerivations1845 client_ca_test.go:139: Found 1 dependencies (including self)18462026/10/06 11:18:26 INFO Received uploads request method=POST path=/api/pending_closures18472026/10/06 11:18:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.160518ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1848=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1849=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1850=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1851=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1852=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1853=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1854=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1855=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1856=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1857=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1858=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1859=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18602026/10/06 11:18:27 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]18612026/10/06 11:18:27 WARN Authentication failed token_preview=eyJhbGciOi...dKXmU9a92Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1862--- PASS: TestService_AuthMiddleware_OIDC (0.38s)1863 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1864 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1865 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1866 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18672026/10/06 11:18:27 INFO Received push request method=POST path=/api/pushes18682026/10/06 11:18:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18692026/10/06 11:18:27 INFO Uploading zsam02xbc8gkddy2pp9b75d96ihpss3d-ca-test (144B)18702026/10/06 11:18:27 WARN Failed to register uploaded object key=log/jlvxh618zhrlymdfwmci6kvfjax9yyjf-ca-test.drv error="server returned 404: 404 page not found\n"18712026/10/06 11:18:27 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18722026/10/06 11:18:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18732026/10/06 11:18:27 WARN Failed to register uploaded object key=zsam02xbc8gkddy2pp9b75d96ihpss3d.ls error="server returned 404: 404 page not found\n"18742026/10/06 11:18:27 INFO Signed narinfos id=1 count=118752026/10/06 11:18:27 INFO Uploading 1 narinfos18762026/10/06 11:18:27 INFO Received complete push request method=POST path=/api/pushes/1/complete18772026/10/06 11:18:27 WARN Failed to register uploaded object key=zsam02xbc8gkddy2pp9b75d96ihpss3d.narinfo error="server returned 404: 404 page not found\n"18782026/10/06 11:18:27 INFO Aborted multipart uploads count=0 kept=018792026/10/06 11:18:27 WARN Force mode enabled - objects will be deleted immediately without grace period18802026/10/06 11:18:27 INFO Upload complete. (98ms)18812026/10/06 11:18:27 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40317/bucket87/?delete=\": context canceled"1882=== NAME TestClientCADerivations1883 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3800425586/001/store/zsam02xbc8gkddy2pp9b75d96ihpss3d-ca-test1884 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1885 Compression: zstd1886 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1887 NarSize: 1441888 References: 1889 Deriver: /build/TestClientCADerivations3800425586/001/store/jlvxh618zhrlymdfwmci6kvfjax9yyjf-ca-test.drv1890 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1891 client_ca_test.go:185: Checking for realisation files in S3...1892 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1893 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18942026/10/06 11:18:27 INFO Received uploads request method=POST path=/api/pending_closures18952026/10/06 11:18:27 INFO Aborted multipart uploads count=0 kept=018962026/10/06 11:18:27 WARN Force mode enabled - objects will be deleted immediately without grace period18972026/10/06 11:18:27 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=018982026/10/06 11:18:27 INFO Vacuumed table table=pending_closures18992026/10/06 11:18:27 INFO Vacuumed table table=pending_objects19002026/10/06 11:18:27 INFO Vacuumed table table=multipart_uploads19012026/10/06 11:18:27 INFO Vacuumed table table=closures19022026/10/06 11:18:27 INFO Vacuumed table table=objects19032026/10/06 11:18:27 INFO Aborted multipart uploads count=0 kept=019042026/10/06 11:18:27 WARN Force mode enabled - objects will be deleted immediately without grace period19052026-10-06 11:18:27.146 UTC [1834] ERROR: canceling statement due to user request19062026-10-06 11:18:27.146 UTC [1834] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block19072026-10-06 11:18:27.146 UTC [1834] STATEMENT: -- name: MarkStaleObjects :execrows1908 WITH RECURSIVE ct AS (1909 SELECT timezone('UTC', now()) AS now1910 ),1911 closure_reach AS (1912 -- Start with all closure keys1913 SELECT o.key, o.refs1914 FROM objects o1915 INNER JOIN closures c ON o.key = c.key1916 UNION1917 -- Recursively add all referenced objects1918 SELECT o.key, o.refs1919 FROM objects o1920 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1921 ),1922 reachable_objects AS (1923 SELECT DISTINCT key FROM closure_reach1924 ),1925 stale_objects AS (1926 SELECT o.key1927 FROM objects AS o, ct1928 WHERE1929 NOT EXISTS (1930 SELECT 11931 FROM reachable_objects ro1932 WHERE ro.key = o.key1933 )1934 AND NOT EXISTS (1935 SELECT 11936 FROM pending_objects AS po1937 WHERE po.key = o.key1938 )1939 AND o.deleted_at IS NULL -- Only mark fresh objects1940 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1941 FOR UPDATE1942 )1943 UPDATE objects1944 SET1945 deleted_at = ct.now,1946 first_deleted_at = COALESCE(first_deleted_at, ct.now)1947 FROM stale_objects, ct1948 WHERE objects.key = stale_objects.key1949 19502026/10/06 11:18:27 INFO Received uploads request method=POST path=/api/pending_closures1951--- PASS: TestGCEndsOnShutdown (0.00s)1952 --- PASS: TestGCEndsOnShutdown/before_the_run (0.28s)1953 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.32s)1954 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.36s)19552026/10/06 11:18:27 INFO Aborted multipart uploads count=0 kept=019562026/10/06 11:18:27 WARN Force mode enabled - objects will be deleted immediately without grace period19572026/10/06 11:18:27 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=019582026/10/06 11:18:27 INFO Vacuumed table table=pending_closures19592026/10/06 11:18:27 INFO Vacuumed table table=pending_objects19602026/10/06 11:18:27 INFO Vacuumed table table=multipart_uploads19612026/10/06 11:18:27 INFO Vacuumed table table=closures19622026/10/06 11:18:27 INFO Vacuumed table table=objects1963--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1964 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.33s)1965 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.36s)19662026/10/06 11:18:27 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.659249ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1967=== NAME TestClientCADerivations1968 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1969 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1970 error: binary cache 's3://bucket80?endpoint=http://localhost:40317®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3800425586/001/store'1971 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11972--- PASS: TestClientCADerivations (0.73s)19732026/10/06 11:18:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1974=== NAME TestOrphanedObjectsGCStressTest1975 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19762026/10/06 11:18:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1977 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19782026/10/06 11:18:27 INFO lead: released remote=192.0.2.1:12341979--- PASS: TestLeadEndsOnShutdown (1.53s)1980--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1981 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)1982 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.08s)1983 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.71s)19842026/10/06 11:18:27 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=794.390525ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19852026/10/06 11:18:27 INFO lead: released remote=192.0.2.1:123419862026/10/06 11:18:27 INFO lead: acquired remote=192.0.2.1:12341987=== NAME TestOrphanedObjectsGCStressTest1988 orphaned_objects_gc_test.go:509: Stress test completed successfully:1989 orphaned_objects_gc_test.go:510: - Active objects preserved: 201990 orphaned_objects_gc_test.go:511: - Objects deleted: 2101991 orphaned_objects_gc_test.go:512: - Total GC'd: 2101992--- PASS: TestOrphanedObjectsGCStressTest (2.72s)1993--- PASS: TestPendingClosureWriteTimeout (0.08s)1994 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1995 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1996 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1997 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.04s)19982026/10/06 11:18:28 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.481330547s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19992026/10/06 11:18:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02000=== NAME TestClientIntegration2001 client_integration_test.go:323: Objects in database after GC:2002 client_integration_test.go:323: Successfully deleted all objects with GC --force2003--- PASS: TestClientIntegration (2.73s)20042026/10/06 11:18:28 INFO lead: released remote=192.0.2.1:12342005--- PASS: TestLeadElectsOneAndHandsOver (2.81s)20062026/10/06 11:18:28 WARN Rate limiter enabled after throttle name=s3-test rate=520072026/10/06 11:18:28 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2008=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2009 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102010 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002011--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.65s)20122026/10/06 11:18:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020132026/10/06 11:18:28 INFO Received create pin request method=POST path=/api/pins/myapp20142026/10/06 11:18:28 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC633308659/001/store/7c1pv6b0p8vh5k0kcv9n96vxjajrn5yh-pinned-file.txt narinfo_key=7c1pv6b0p8vh5k0kcv9n96vxjajrn5yh.narinfo20152026/10/06 11:18:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures20162026/10/06 11:18:28 INFO Garbage collection started20172026/10/06 11:18:28 INFO Aborted multipart uploads count=0 kept=020182026/10/06 11:18:28 WARN Force mode enabled - objects will be deleted immediately without grace period20192026/10/06 11:18:28 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=020202026/10/06 11:18:28 INFO Vacuumed table table=pending_closures20212026/10/06 11:18:28 INFO Vacuumed table table=pending_objects20222026/10/06 11:18:28 INFO Vacuumed table table=multipart_uploads20232026/10/06 11:18:28 INFO Vacuumed table table=closures20242026/10/06 11:18:28 INFO Vacuumed table table=objects2025--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.88s)20262026/10/06 11:18:29 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-config20272026/10/06 11:18:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.219433ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 11:18:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.410381ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/06 11:18:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=757.345308ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2030=== NAME TestPinProtectsFromGC2031 client_integration_test.go:840: Pin successfully protected closure from garbage collection2032--- PASS: TestPinProtectsFromGC (4.79s)2033--- PASS: TestConnectWaitsForAPeerMigration (5.19s)20342026/10/06 11:18:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.704149708s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/06 11:18:31 INFO Aborted multipart uploads count=1 kept=020362026/10/06 11:18:31 INFO Received cleanup request method=DELETE path=/api/pending_closures20372026/10/06 11:18:31 INFO Aborted multipart uploads count=1 kept=02038--- PASS: TestPendingCleanupUsesOneCutoff (6.68s)20392026/10/06 11:18:33 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"20402026/10/06 11:18:33 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-config20412026/10/06 11:18:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.871102ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/06 11:18:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.497567ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20432026/10/06 11:18:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=786.75796ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20442026/10/06 11:18:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.51079009s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20452026/10/06 11:18:36 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_closures20462026/10/06 11:18:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.994194ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20472026/10/06 11:18:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.584416ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20482026/10/06 11:18:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=787.444722ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20492026/10/06 11:18:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.657938557s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2050--- PASS: TestClientErrorHandling (0.00s)2051 --- PASS: TestClientErrorHandling/InvalidStorePath (0.40s)2052 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.46s)2053 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.48s)2054PASS20552026-10-06 11:18:39.687 UTC [129] LOG: received smart shutdown request20562026-10-06 11:18:39.690 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120572026-10-06 11:18:39.704 UTC [134] LOG: shutting down20582026-10-06 11:18:39.705 UTC [134] LOG: checkpoint starting: shutdown immediate20592026-10-06 11:18:41.388 UTC [134] LOG: checkpoint complete: wrote 11301 buffers (69.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.283 s, sync=1.359 s, total=1.684 s; sync files=31336, longest=0.012 s, average=0.001 s; distance=433018 kB, estimate=433018 kB; lsn=0/1BE446F8, redo lsn=0/1BE446F820602026-10-06 11:18:41.447 UTC [129] LOG: database system is shut down2061Running OIDC tests...2062=== RUN TestAudienceForIssuer2063=== PAUSE TestAudienceForIssuer2064=== RUN TestGlobMatch2065=== PAUSE TestGlobMatch2066=== RUN TestValidateToken_ValidToken2067=== PAUSE TestValidateToken_ValidToken2068=== RUN TestValidateToken_WrongAudience2069=== PAUSE TestValidateToken_WrongAudience2070=== RUN TestValidateToken_Expired2071=== PAUSE TestValidateToken_Expired2072=== RUN TestValidateToken_BoundClaimsMismatch2073=== PAUSE TestValidateToken_BoundClaimsMismatch2074=== RUN TestValidateToken_BoundSubjectMismatch2075=== PAUSE TestValidateToken_BoundSubjectMismatch2076=== RUN TestValidateToken_MultipleProviders2077=== PAUSE TestValidateToken_MultipleProviders2078=== RUN TestValidateToken_NoMatchingProvider2079=== PAUSE TestValidateToken_NoMatchingProvider2080=== RUN TestValidateToken_KubernetesServiceAccount2081=== PAUSE TestValidateToken_KubernetesServiceAccount2082=== RUN TestNewValidator_KubernetesRequiresCA2083=== PAUSE TestNewValidator_KubernetesRequiresCA2084=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2085=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2086=== RUN TestPins_ReservedForMatchingRule2087=== PAUSE TestPins_ReservedForMatchingRule2088=== RUN TestPins_TopLevelShorthand2089=== PAUSE TestPins_TopLevelShorthand2090=== RUN TestPins_ConfigValidation2091=== PAUSE TestPins_ConfigValidation2092=== RUN TestScopes_LegacyProviderDefaultsToWrite2093=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2094=== RUN TestScopes_Rules2095=== PAUSE TestScopes_Rules2096=== RUN TestScopes_ConfigValidation2097=== PAUSE TestScopes_ConfigValidation2098=== CONT TestAudienceForIssuer2099=== CONT TestValidateToken_BoundClaimsMismatch2100--- PASS: TestAudienceForIssuer (0.00s)2101=== CONT TestValidateToken_Expired2102=== CONT TestValidateToken_WrongAudience2103=== CONT TestValidateToken_ValidToken2104=== CONT TestValidateToken_KubernetesServiceAccount2105=== CONT TestGlobMatch2106=== RUN TestGlobMatch/foo_foo2107=== PAUSE TestGlobMatch/foo_foo2108=== RUN TestGlobMatch/foo_bar2109=== PAUSE TestGlobMatch/foo_bar2110=== RUN TestGlobMatch/*_2111=== PAUSE TestGlobMatch/*_2112=== RUN TestGlobMatch/*_anything2113=== PAUSE TestGlobMatch/*_anything2114=== RUN TestGlobMatch/foo*_foo2115=== PAUSE TestGlobMatch/foo*_foo2116=== RUN TestGlobMatch/foo*_foobar2117=== PAUSE TestGlobMatch/foo*_foobar2118=== RUN TestGlobMatch/foo*_bar2119=== PAUSE TestGlobMatch/foo*_bar2120=== RUN TestGlobMatch/*bar_bar2121=== PAUSE TestGlobMatch/*bar_bar2122=== RUN TestGlobMatch/*bar_foobar2123=== PAUSE TestGlobMatch/*bar_foobar2124=== RUN TestGlobMatch/*bar_foo2125=== PAUSE TestGlobMatch/*bar_foo2126=== RUN TestGlobMatch/foo*bar_foobar2127=== PAUSE TestGlobMatch/foo*bar_foobar2128=== RUN TestGlobMatch/foo*bar_foo123bar2129=== PAUSE TestGlobMatch/foo*bar_foo123bar2130=== RUN TestGlobMatch/foo*bar_foobarbaz2131=== PAUSE TestGlobMatch/foo*bar_foobarbaz2132=== RUN TestGlobMatch/*/*_foo/bar2133=== PAUSE TestGlobMatch/*/*_foo/bar2134=== RUN TestGlobMatch/*/*_foo2135=== PAUSE TestGlobMatch/*/*_foo2136=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2137=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2138=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02139=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02140=== RUN TestGlobMatch/refs/*/main_refs/heads/main2141=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2142=== RUN TestGlobMatch/fo?_foo2143=== PAUSE TestGlobMatch/fo?_foo2144=== RUN TestGlobMatch/fo?_fo2145=== PAUSE TestGlobMatch/fo?_fo2146=== RUN TestGlobMatch/fo?_fooo2147=== PAUSE TestGlobMatch/fo?_fooo2148=== RUN TestGlobMatch/?oo_foo2149=== PAUSE TestGlobMatch/?oo_foo2150=== RUN TestGlobMatch/?oo_boo2151=== PAUSE TestGlobMatch/?oo_boo2152=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2153=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2154=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2155=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2156=== CONT TestGlobMatch/foo_foo2157=== CONT TestPins_TopLevelShorthand2158=== CONT TestGlobMatch/*/*_foo/bar2159=== CONT TestGlobMatch/fo?_foo2160=== CONT TestGlobMatch/?oo_boo2161=== CONT TestGlobMatch/*bar_foo2162=== CONT TestGlobMatch/*bar_foobar2163=== CONT TestPins_ReservedForMatchingRule2164=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2165=== CONT TestScopes_ConfigValidation2166=== CONT TestNewValidator_KubernetesRequiresCA2167=== CONT TestScopes_LegacyProviderDefaultsToWrite2168=== CONT TestValidateToken_MultipleProviders2169=== CONT TestValidateToken_NoMatchingProvider2170=== CONT TestValidateToken_BoundSubjectMismatch2171=== CONT TestPins_ConfigValidation2172=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2173=== CONT TestGlobMatch/refs/*/main_refs/heads/main2174=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2175=== CONT TestGlobMatch/?oo_foo2176=== CONT TestGlobMatch/*bar_bar2177=== CONT TestGlobMatch/foo*bar_foobarbaz2178=== CONT TestGlobMatch/foo*bar_foo123bar2179=== CONT TestScopes_Rules2180=== CONT TestGlobMatch/foo*bar_foobar2181=== CONT TestGlobMatch/fo?_fooo2182--- PASS: TestScopes_ConfigValidation (0.00s)2183=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02184=== CONT TestGlobMatch/foo*_foo2185=== CONT TestGlobMatch/*_2186=== CONT TestGlobMatch/*_anything2187=== CONT TestGlobMatch/foo*_foobar2188=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2189=== CONT TestGlobMatch/foo_bar2190=== CONT TestGlobMatch/*/*_foo2191=== CONT TestGlobMatch/fo?_fo2192=== CONT TestGlobMatch/foo*_bar2193--- PASS: TestPins_ConfigValidation (0.00s)2194--- PASS: TestGlobMatch (0.00s)2195 --- PASS: TestGlobMatch/foo_foo (0.00s)2196 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2197 --- PASS: TestGlobMatch/fo?_foo (0.00s)2198 --- PASS: TestGlobMatch/?oo_boo (0.00s)2199 --- PASS: TestGlobMatch/*bar_foo (0.00s)2200 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2201 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2202 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2203 --- PASS: TestGlobMatch/*bar_bar (0.00s)2204 --- PASS: TestGlobMatch/?oo_foo (0.00s)2205 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2206 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2207 --- PASS: TestGlobMatch/foo*_foo (0.00s)2208 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2209 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2210 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2211 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2212 --- PASS: TestGlobMatch/*_ (0.00s)2213 --- PASS: TestGlobMatch/*_anything (0.00s)2214 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2215 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2216 --- PASS: TestGlobMatch/foo_bar (0.00s)2217 --- PASS: TestGlobMatch/*/*_foo (0.00s)2218 --- PASS: TestGlobMatch/fo?_fo (0.00s)2219 --- PASS: TestGlobMatch/foo*_bar (0.00s)22202026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37561/oidc2221--- PASS: TestValidateToken_ValidToken (0.02s)22222026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43097/oidc2223--- PASS: TestValidateToken_WrongAudience (0.04s)22242026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34619/oidc2225--- PASS: TestValidateToken_Expired (0.04s)22262026/10/06 11:18:43 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322272026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39573/oidc22282026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38069/oidc2229--- PASS: TestPins_TopLevelShorthand (0.06s)22302026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36541/oidc2231--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)2232--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)22332026/10/06 11:18:43 http: TLS handshake error from 127.0.0.1:54370: remote error: tls: bad certificate2234--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)2235--- PASS: TestScopes_Rules (0.06s)22362026/10/06 11:18:43 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:416212237--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)22382026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43985/oidc2239--- PASS: TestPins_ReservedForMatchingRule (0.12s)22402026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40293/oidc2241--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)22422026/10/06 11:18:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38465/oidc2243--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)22442026/10/06 11:18:43 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34269/oidc2245--- PASS: TestValidateToken_NoMatchingProvider (0.18s)22462026/10/06 11:18:43 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44081/oidc22472026/10/06 11:18:43 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37963/oidc2248--- PASS: TestValidateToken_MultipleProviders (0.19s)2249PASS2250Running hook tests...2251=== RUN TestSendPathsEmpty2252=== PAUSE TestSendPathsEmpty2253=== RUN TestQueueEnqueueAndFetch2254=== PAUSE TestQueueEnqueueAndFetch2255=== RUN TestQueueDeduplication2256=== PAUSE TestQueueDeduplication2257=== RUN TestQueueRemove2258=== PAUSE TestQueueRemove2259=== RUN TestQueueFetchBatchLimit2260=== PAUSE TestQueueFetchBatchLimit2261=== RUN TestQueueRetryMovesToBack2262=== PAUSE TestQueueRetryMovesToBack2263=== RUN TestQueueFetchRemoveLifecycle2264=== PAUSE TestQueueFetchRemoveLifecycle2265=== RUN TestQueueConcurrentWriters2266=== PAUSE TestQueueConcurrentWriters2267=== RUN TestQueueRemoveLargeClosure2268=== PAUSE TestQueueRemoveLargeClosure2269=== RUN TestServerClientIntegration2270=== PAUSE TestServerClientIntegration2271=== RUN TestServerQueueError2272=== PAUSE TestServerQueueError2273=== RUN TestGetListenerSocketActivation2274 server_test.go:210: === RUN TestGetListenerSocketActivation2275 --- PASS: TestGetListenerSocketActivation (0.00s)2276 PASS2277 2278--- PASS: TestGetListenerSocketActivation (0.01s)2279=== RUN TestDrainIsolatesPoisonPath2280=== PAUSE TestDrainIsolatesPoisonPath2281=== RUN TestRunNotBlockedByPoisonHead2282=== PAUSE TestRunNotBlockedByPoisonHead2283=== RUN TestDrainGivesUpWhenServerDown2284=== PAUSE TestDrainGivesUpWhenServerDown2285=== RUN TestFailedPathPrunedByLaterClosure2286=== PAUSE TestFailedPathPrunedByLaterClosure2287=== RUN TestWorkerUploadsAndRemoves2288=== PAUSE TestWorkerUploadsAndRemoves2289=== RUN TestWorkerSkipsGCdPaths2290=== PAUSE TestWorkerSkipsGCdPaths2291=== RUN TestWorkerPrunesClosureDeps2292=== PAUSE TestWorkerPrunesClosureDeps2293=== RUN TestDrainTimeout2294=== PAUSE TestDrainTimeout2295=== CONT TestSendPathsEmpty2296=== CONT TestServerQueueError2297=== CONT TestWorkerUploadsAndRemoves2298=== CONT TestDrainGivesUpWhenServerDown2299=== CONT TestServerClientIntegration2300=== CONT TestQueueRemoveLargeClosure23012026/10/06 11:18:43 ERROR Failed to queue paths error="permission denied" count=12302=== CONT TestQueueConcurrentWriters2303=== CONT TestQueueFetchRemoveLifecycle2304=== CONT TestQueueRetryMovesToBack2305=== CONT TestQueueFetchBatchLimit2306=== CONT TestQueueRemove2307=== CONT TestQueueDeduplication2308=== CONT TestQueueEnqueueAndFetch2309=== CONT TestFailedPathPrunedByLaterClosure2310=== CONT TestRunNotBlockedByPoisonHead2311=== CONT TestDrainIsolatesPoisonPath2312=== CONT TestWorkerPrunesClosureDeps2313=== CONT TestDrainTimeout2314=== CONT TestWorkerSkipsGCdPaths2315--- PASS: TestSendPathsEmpty (0.00s)2316--- PASS: TestServerQueueError (0.00s)2317--- PASS: TestServerClientIntegration (0.00s)23182026/10/06 11:18:43 INFO Upload queue status pending=223192026/10/06 11:18:43 INFO Uploading batch count=223202026/10/06 11:18:43 INFO Upload queue status pending=323212026/10/06 11:18:43 INFO Uploading batch count=123222026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=123232026/10/06 11:18:43 INFO Upload queue status pending=223242026/10/06 11:18:43 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2418120558/002/nonexistent23252026/10/06 11:18:43 INFO Uploading batch count=123262026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=123272026/10/06 11:18:43 INFO Uploading batch count=223282026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=223292026/10/06 11:18:43 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3479104509/002/a23302026/10/06 11:18:43 INFO Uploading batch count=42331--- PASS: TestQueueEnqueueAndFetch (0.02s)23322026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=423332026/10/06 11:18:43 INFO Uploading batch count=22334--- PASS: TestQueueFetchBatchLimit (0.02s)2335--- PASS: TestQueueDeduplication (0.02s)23362026/10/06 11:18:43 INFO Uploading batch count=123372026/10/06 11:18:43 INFO Upload queue status pending=223382026/10/06 11:18:43 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3479104509/002/b2339--- PASS: TestQueueRemove (0.02s)23402026/10/06 11:18:43 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath947590142/002/bbb23412026/10/06 11:18:43 INFO Uploading batch count=123422026/10/06 11:18:43 INFO Uploading batch count=12343--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23442026/10/06 11:18:43 INFO Uploading batch count=223452026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=223462026/10/06 11:18:43 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3479104509/002/c23472026/10/06 11:18:43 INFO Uploading batch count=12348--- PASS: TestQueueRetryMovesToBack (0.02s)23492026/10/06 11:18:43 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3479104509/002/d23502026/10/06 11:18:43 INFO Uploading batch count=123512026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=123522026/10/06 11:18:43 INFO Uploading batch count=223532026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=223542026/10/06 11:18:43 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3479104509/002/e23552026/10/06 11:18:43 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3479104509/002/f23562026/10/06 11:18:43 INFO Uploading batch count=123572026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=12358--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23592026/10/06 11:18:43 INFO Uploading batch count=123602026/10/06 11:18:43 ERROR Upload failed error="upload failed" count=123612026/10/06 11:18:43 ERROR Drain finished with paths left in queue remaining=1023622026/10/06 11:18:43 ERROR Drain finished with paths left in queue remaining=12363--- PASS: TestDrainIsolatesPoisonPath (0.02s)2364--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2365--- PASS: TestWorkerUploadsAndRemoves (0.04s)2366--- PASS: TestWorkerSkipsGCdPaths (0.03s)2367--- PASS: TestWorkerPrunesClosureDeps (0.04s)2368--- PASS: TestQueueRemoveLargeClosure (0.06s)23692026/10/06 11:18:43 ERROR Upload failed error="context deadline exceeded" count=223702026/10/06 11:18:43 ERROR Drain finished with paths left in queue remaining=42371--- PASS: TestDrainTimeout (0.22s)2372--- PASS: TestQueueConcurrentWriters (0.28s)23732026/10/06 11:18:44 INFO Uploading batch count=123742026/10/06 11:18:44 INFO Uploading batch count=123752026/10/06 11:18:44 INFO Uploading batch count=123762026/10/06 11:18:44 ERROR Upload failed error="upload failed" count=123772026/10/06 11:18:44 INFO Uploading batch count=123782026/10/06 11:18:44 ERROR Upload failed error="upload failed" count=123792026/10/06 11:18:44 INFO Uploading batch count=123802026/10/06 11:18:44 ERROR Upload failed error="upload failed" count=123812026/10/06 11:18:44 INFO Uploading batch count=123822026/10/06 11:18:44 ERROR Upload failed error="upload failed" count=123832026/10/06 11:18:44 ERROR Drain finished with paths left in queue remaining=12384--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2385PASS2386Running signing tests...2387=== RUN TestExternalSigner2388=== PAUSE TestExternalSigner2389=== RUN TestExternalSignerWrongPublicKey2390=== PAUSE TestExternalSignerWrongPublicKey2391=== RUN TestExternalSignerErrors2392=== PAUSE TestExternalSignerErrors2393=== RUN TestExternalSignerRestartsAfterCrash2394=== PAUSE TestExternalSignerRestartsAfterCrash2395=== RUN TestExternalSignerProgramErrorKeepsProcess2396=== PAUSE TestExternalSignerProgramErrorKeepsProcess2397=== RUN TestExternalSignerClose2398=== PAUSE TestExternalSignerClose2399=== RUN TestExternalSignerRejectsInvalidPublicKey2400=== PAUSE TestExternalSignerRejectsInvalidPublicKey2401=== RUN TestExternalSignerCancellation2402=== PAUSE TestExternalSignerCancellation2403=== RUN TestGenerateFingerprint2404=== PAUSE TestGenerateFingerprint2405=== RUN TestParseSigningKey2406=== PAUSE TestParseSigningKey2407=== RUN TestSign2408=== PAUSE TestSign2409=== RUN TestSignBatch2410=== PAUSE TestSignBatch2411=== RUN TestNilKeyPublicKey2412=== PAUSE TestNilKeyPublicKey2413=== RUN TestSignErrors2414=== PAUSE TestSignErrors2415=== CONT TestExternalSigner2416=== CONT TestExternalSignerCancellation2417=== CONT TestSignBatch2418=== CONT TestParseSigningKey2419=== CONT TestGenerateFingerprint2420=== CONT TestNilKeyPublicKey2421--- PASS: TestNilKeyPublicKey (0.00s)2422=== CONT TestExternalSignerProgramErrorKeepsProcess2423=== CONT TestExternalSignerRejectsInvalidPublicKey2424=== RUN TestExternalSignerRejectsInvalidPublicKey/#002425=== CONT TestExternalSignerErrors2426=== CONT TestExternalSignerClose2427=== CONT TestExternalSignerRestartsAfterCrash2428=== CONT TestExternalSignerWrongPublicKey2429=== CONT TestSignErrors2430=== CONT TestSign2431=== RUN TestParseSigningKey/valid_32-byte_key2432=== RUN TestGenerateFingerprint/basic_with_references2433=== PAUSE TestGenerateFingerprint/basic_with_references2434=== RUN TestGenerateFingerprint/no_references2435=== PAUSE TestGenerateFingerprint/no_references2436=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2437=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2438=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2439=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002440=== RUN TestExternalSignerErrors/missing_signatures2441=== PAUSE TestExternalSignerErrors/missing_signatures2442=== RUN TestExternalSignerErrors/program_error2443=== PAUSE TestExternalSignerErrors/program_error2444=== RUN TestExternalSignerErrors/exit_on_request2445=== PAUSE TestExternalSignerErrors/exit_on_request2446=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2447=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2448=== PAUSE TestParseSigningKey/valid_32-byte_key2449=== RUN TestSignErrors/nil_key2450=== PAUSE TestSignErrors/nil_key2451=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2452=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2453--- PASS: TestSign (0.00s)2454=== RUN TestExternalSignerErrors/wrong_shape2455--- PASS: TestSignBatch (0.00s)2456=== PAUSE TestExternalSignerErrors/wrong_shape2457=== RUN TestSignErrors/nil_narinfo2458=== PAUSE TestSignErrors/nil_narinfo2459=== RUN TestSignErrors/invalid_narinfo2460=== PAUSE TestSignErrors/invalid_narinfo2461=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2462=== RUN TestGenerateFingerprint/invalid_nar_hash_length2463=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2464=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2465=== RUN TestExternalSignerErrors/null_signatures2466=== PAUSE TestExternalSignerErrors/null_signatures2467=== RUN TestSignErrors/canceled2468=== PAUSE TestSignErrors/canceled2469=== CONT TestSignErrors/nil_key2470=== RUN TestParseSigningKey/no_colon2471=== PAUSE TestParseSigningKey/no_colon2472=== RUN TestParseSigningKey/empty_name2473=== RUN TestGenerateFingerprint/invalid_store_path_prefix2474=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2475=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2476=== RUN TestExternalSignerErrors/wrong_signatures_shape2477=== CONT TestSignErrors/invalid_narinfo2478=== CONT TestSignErrors/nil_narinfo2479=== CONT TestSignErrors/canceled2480=== PAUSE TestParseSigningKey/empty_name2481=== RUN TestGenerateFingerprint/invalid_reference_prefix2482=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2483=== CONT TestGenerateFingerprint/basic_with_references2484=== CONT TestGenerateFingerprint/no_references2485=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2486=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2487=== CONT TestGenerateFingerprint/invalid_reference_prefix2488=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2489=== RUN TestExternalSignerErrors/invalid_JSON2490=== PAUSE TestExternalSignerErrors/invalid_JSON2491--- PASS: TestSignErrors (0.00s)2492 --- PASS: TestSignErrors/nil_key (0.00s)2493 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2494 --- PASS: TestSignErrors/nil_narinfo (0.00s)2495 --- PASS: TestSignErrors/canceled (0.00s)2496=== RUN TestParseSigningKey/invalid_base642497=== PAUSE TestParseSigningKey/invalid_base642498=== RUN TestParseSigningKey/wrong_length2499=== PAUSE TestParseSigningKey/wrong_length2500=== CONT TestParseSigningKey/valid_32-byte_key2501=== CONT TestParseSigningKey/empty_name2502=== CONT TestParseSigningKey/wrong_length2503=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2504=== CONT TestParseSigningKey/no_colon2505=== CONT TestGenerateFingerprint/invalid_store_path_prefix2506=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2507=== CONT TestGenerateFingerprint/invalid_nar_hash_length2508=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2509=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2510=== CONT TestExternalSignerRejectsInvalidPublicKey/#002511=== RUN TestExternalSignerErrors/too_few_signatures2512=== PAUSE TestExternalSignerErrors/too_few_signatures2513=== RUN TestExternalSignerErrors/wrong_signature_length2514=== PAUSE TestExternalSignerErrors/wrong_signature_length2515=== RUN TestExternalSignerErrors/exit_at_startup2516=== PAUSE TestExternalSignerErrors/exit_at_startup2517=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2518--- PASS: TestExternalSignerWrongPublicKey (0.00s)2519=== CONT TestParseSigningKey/invalid_base642520=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2521=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2522=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2523=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2524=== RUN TestExternalSignerErrors/null2525=== PAUSE TestExternalSignerErrors/null2526=== RUN TestExternalSignerErrors/wrong_id2527=== PAUSE TestExternalSignerErrors/wrong_id2528=== RUN TestExternalSignerErrors/unrequested_key2529=== PAUSE TestExternalSignerErrors/unrequested_key2530=== RUN TestExternalSignerErrors/missing_signature_name2531--- PASS: TestExternalSignerClose (0.00s)2532=== PAUSE TestExternalSignerErrors/missing_signature_name2533=== RUN TestExternalSignerErrors/wrong_signature_name2534--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2535=== PAUSE TestExternalSignerErrors/wrong_signature_name2536=== RUN TestExternalSignerErrors/invalid_signature_base642537=== PAUSE TestExternalSignerErrors/invalid_signature_base642538=== CONT TestExternalSignerErrors/missing_signatures2539=== CONT TestExternalSignerErrors/invalid_JSON2540--- PASS: TestGenerateFingerprint (0.00s)2541 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2542 --- PASS: TestGenerateFingerprint/no_references (0.00s)2543 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2544 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2545 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2546 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2547 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2548=== CONT TestExternalSignerErrors/unrequested_key2549--- PASS: TestParseSigningKey (0.00s)2550 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2551 --- PASS: TestParseSigningKey/empty_name (0.00s)2552 --- PASS: TestParseSigningKey/wrong_length (0.00s)2553 --- PASS: TestParseSigningKey/no_colon (0.00s)2554 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2555 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2556=== CONT TestExternalSignerErrors/missing_signature_name2557=== CONT TestExternalSignerErrors/invalid_signature_base642558=== CONT TestExternalSignerErrors/wrong_signature_name2559=== CONT TestExternalSignerErrors/too_few_signatures2560=== CONT TestExternalSignerErrors/null_signatures2561=== CONT TestExternalSignerErrors/exit_at_startup2562=== CONT TestExternalSignerErrors/null2563=== CONT TestExternalSignerErrors/wrong_signature_length2564=== CONT TestExternalSignerErrors/exit_on_request2565=== CONT TestExternalSignerErrors/wrong_id2566=== CONT TestExternalSignerErrors/wrong_shape2567=== CONT TestExternalSignerErrors/program_error2568=== CONT TestExternalSignerErrors/wrong_signatures_shape2569--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2570 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2571 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2572 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2573 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2574 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2575--- PASS: TestExternalSigner (0.01s)2576--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2577--- PASS: TestExternalSignerErrors (0.01s)2578 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2579 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2580 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2581 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2582 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2583 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2584 --- PASS: TestExternalSignerErrors/program_error (0.00s)2585 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2586 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2587 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2588 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2589 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2590 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2591 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2592 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2593 --- PASS: TestExternalSignerErrors/null (0.01s)2594--- PASS: TestExternalSignerCancellation (0.02s)2595PASS2596Running OpenBao signer tests...2597=== RUN TestSign2598=== PAUSE TestSign2599=== RUN TestSignErrors2600=== PAUSE TestSignErrors2601=== RUN TestServe2602=== PAUSE TestServe2603=== RUN TestServeRejectsGarbage2604=== PAUSE TestServeRejectsGarbage2605=== CONT TestSign2606=== CONT TestServe2607=== CONT TestSignErrors2608=== CONT TestServeRejectsGarbage2609=== RUN TestSignErrors/http_error2610=== PAUSE TestSignErrors/http_error2611=== RUN TestSignErrors/invalid_json2612=== PAUSE TestSignErrors/invalid_json2613=== RUN TestSignErrors/no_prefix2614=== PAUSE TestSignErrors/no_prefix2615=== RUN TestSignErrors/invalid_base642616=== PAUSE TestSignErrors/invalid_base642617=== CONT TestSignErrors/http_error2618=== CONT TestSignErrors/no_prefix2619--- PASS: TestServeRejectsGarbage (0.00s)2620=== CONT TestSignErrors/invalid_json2621=== CONT TestSignErrors/invalid_base642622--- PASS: TestServe (0.00s)2623--- PASS: TestSign (0.00s)2624--- PASS: TestSignErrors (0.00s)2625 --- PASS: TestSignErrors/invalid_base64 (0.00s)2626 --- PASS: TestSignErrors/http_error (0.00s)2627 --- PASS: TestSignErrors/no_prefix (0.00s)2628 --- PASS: TestSignErrors/invalid_json (0.00s)2629PASS