niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #368
· 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.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== CONT TestResolveStorePath103=== CONT TestSetClientTLSErrors104=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess105=== CONT TestScriptTokenEmptyCommand106--- PASS: TestScriptTokenEmptyCommand (0.00s)107=== CONT TestClientSignaturesByStorePath108--- PASS: TestClientSignaturesByStorePath (0.00s)109=== CONT TestStreamPushReportsEveryPath110=== CONT TestScriptTokenScriptFails1112026/10/06 10:42:35 WARN Rate limiter enabled after throttle name=server-test rate=5112=== CONT TestRateLimiterFeedback113=== RUN TestRateLimiterFeedback/429_enables_limiter114=== PAUSE TestRateLimiterFeedback/429_enables_limiter115=== CONT TestScriptTokenBadJSON116=== CONT TestPathInfoCACompatibility117=== CONT TestScriptTokenEmptyToken118=== CONT TestParsePathInfoJSONMultiplePaths119=== CONT TestScriptTokenCachesUntilRefresh120=== CONT TestParsePathInfoJSON121=== CONT TestScriptTokenNoExpiryRerunsEveryCall122=== CONT TestPathInfoHashCompatibility123=== CONT TestFileTokenEmpty124=== CONT TestGetStorePathHash125=== CONT TestFileTokenMissing126=== CONT TestConvertHashToNix32127=== CONT TestFileTokenReadsAndCaches128=== CONT TestEncodeNixBase32WithRealHash129=== CONT TestStaticToken130=== RUN TestEncodeNixBase32/test_string_hash131=== RUN TestRateLimiterFeedback/503_enables_limiter132--- PASS: TestStaticToken (0.00s)133=== CONT TestStreamPushIsolatesFailures134--- PASS: TestResolveStorePath (0.00s)135=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1362026/10/06 10:42:35 ERROR Upload failed error="bad path" count=3137=== RUN TestParsePathInfoJSON/Nix_format138=== PAUSE TestParsePathInfoJSON/Nix_format139=== RUN TestParsePathInfoJSON/Lix_format140=== PAUSE TestParsePathInfoJSON/Lix_format141=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths142--- PASS: TestStreamPushReportsEveryPath (0.00s)143=== CONT TestStreamPushReportsSignatures144=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths145=== RUN TestParsePathInfoJSON/empty_input146=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)147=== PAUSE TestRateLimiterFeedback/503_enables_limiter148=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== PAUSE TestParsePathInfoJSON/empty_input150=== RUN TestGetStorePathHash/valid_store_path151=== PAUSE TestGetStorePathHash/valid_store_path1522026/10/06 10:42:35 ERROR Upload failed error=boom count=1153=== CONT TestShellSplitErrors154=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun155=== CONT TestStreamPushBatchesUnderLoad156=== CONT TestFilterOversizedClosures157=== RUN TestFilterOversizedClosures/no_limit_keeps_everything158=== CONT TestUploadMultipart_PartsInParallel159=== RUN TestGetStorePathHash/basename_without_hyphen_should_error160=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== CONT TestSetClientTLS162=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter163=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon164--- PASS: TestStreamPushIsolatesFailures (0.00s)165=== RUN TestParsePathInfoJSON/whitespace_only166=== RUN TestConvertHashToNix32/SRI_format_to_Nix32167=== CONT TestSetClientTLSDoesNotMutateDefaultTransport168--- PASS: TestScriptTokenScriptFails (0.00s)169=== RUN TestPathInfoCACompatibility/null_ca_field170=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything171=== PAUSE TestEncodeNixBase32/test_string_hash1722026/10/06 10:42:35 WARN Rate limiter enabled after throttle name=server-test rate=5173--- PASS: TestEncodeNixBase32WithRealHash (0.00s)174--- PASS: TestStreamPushReportsSignatures (0.00s)1752026/10/06 10:42:35 INFO Garbage collection started1762026/10/06 10:42:35 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37869177--- PASS: TestShellSplitErrors (0.00s)178--- PASS: TestFileTokenMissing (0.00s)179--- PASS: TestFileTokenReadsAndCaches (0.00s)180--- PASS: TestFileTokenEmpty (0.00s)181=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped182=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica183=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped184=== CONT TestStreamPushRequestLine185=== CONT TestCaseHackSuffix1862026/10/06 10:42:35 ERROR Upload failed error=boom count=1187=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error188=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon189=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1902026/10/06 10:42:35 WARN Rate limiter backed off name=server-test rate=5191=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1922026/10/06 10:42:35 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37869193=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter194=== PAUSE TestParsePathInfoJSON/whitespace_only195=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32196=== PAUSE TestPathInfoCACompatibility/null_ca_field197=== RUN TestEncodeNixBase32/empty_input198--- PASS: TestDoServerRequestAttachesToken (0.01s)199=== RUN TestFilterOversizedClosures/all_closures_skipped200=== CONT TestDumpPathWriterError201=== RUN TestSetClientTLSErrors/missing_cert_file202=== RUN TestSetClientTLS/rejects_connection_without_client_cert203=== CONT TestDumpPathSingleFile204=== CONT TestDumpPathMatchesNix205=== CONT TestUploadMultipart_SupersededByPeer206=== RUN TestUploadMultipart_SupersededByPeer/exists207=== PAUSE TestSetClientTLSErrors/missing_cert_file2082026/10/06 10:42:35 INFO Garbage collection started209=== RUN TestSetClientTLSErrors/missing_key_file210=== PAUSE TestUploadMultipart_SupersededByPeer/exists211=== RUN TestParsePathInfoJSON/invalid_JSON212=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512213=== RUN TestUploadMultipart_SupersededByPeer/missing214=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter215=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter216=== RUN TestConvertHashToNix32/already_Nix32_format217=== PAUSE TestConvertHashToNix32/already_Nix32_format218=== PAUSE TestEncodeNixBase32/empty_input219=== CONT TestRegisterUploadedObjectReusesConnections220=== PAUSE TestFilterOversizedClosures/all_closures_skipped221=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths222=== RUN TestPathInfoCACompatibility/old_string_format_-_text223=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text224=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive225=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive226=== RUN TestPathInfoCACompatibility/new_structured_format_-_text227=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text228=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method229=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths230=== CONT TestRateLimiterFeedback/429_enables_limiter231--- PASS: TestScriptTokenEmptyToken (0.00s)232--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)233--- PASS: TestScriptTokenBadJSON (0.07s)234--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.07s)235--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.07s)2362026/10/06 10:42:35 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=0237=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method238--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)239 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)240 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)241=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert242=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA243=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA244=== RUN TestSetClientTLS/preserves_debug_logging_transport245=== PAUSE TestSetClientTLS/preserves_debug_logging_transport246=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter247=== CONT TestShellSplit248--- PASS: TestShellSplit (0.00s)249=== CONT TestRateLimiterFeedback/503_enables_limiter250=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2512026/10/06 10:42:35 WARN Rate limiter enabled after throttle name=server-test rate=5252=== PAUSE TestSetClientTLSErrors/missing_key_file2532026/10/06 10:42:35 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:43171254=== RUN TestSetClientTLSErrors/missing_ca_file255=== PAUSE TestSetClientTLSErrors/missing_ca_file256=== RUN TestSetClientTLSErrors/invalid_ca_file257=== PAUSE TestSetClientTLSErrors/invalid_ca_file258=== CONT TestEncodeNixBase32/test_string_hash259=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error260=== CONT TestPartSizeForNAR261=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5122622026/10/06 10:42:35 WARN Rate limiter backed off name=server-test rate=5263=== PAUSE TestParsePathInfoJSON/invalid_JSON264=== PAUSE TestUploadMultipart_SupersededByPeer/missing265=== RUN TestConvertHashToNix32/invalid_format266=== CONT TestStreamPushGivesUpOnDeadServer267=== CONT TestEncodeNixBase32/empty_input268=== CONT TestFilterOversizedClosures/all_closures_skipped2692026/10/06 10:42:35 WARN Garbage collection finished on another replica. Its statistics are not available here2702026/10/06 10:42:35 WARN Rate limiter enabled after throttle name=server-test rate=5271--- PASS: TestEncodeNixBase32 (0.07s)272 --- PASS: TestEncodeNixBase32/empty_input (0.00s)273 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)2742026/10/06 10:42:35 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35525275=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error276=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error277=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error278=== RUN TestPartSizeForNAR/zero_stays_at_minimum279=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum280=== CONT TestSetClientTLS/rejects_connection_without_client_cert281--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.07s)282=== PAUSE TestConvertHashToNix32/invalid_format2832026/10/06 10:42:35 ERROR Upload failed error="connection refused" count=202842026/10/06 10:42:35 ERROR Server seems unavailable, giving up on batch untried=17285=== RUN TestPartSizeForNAR/small_stays_at_minimum286=== PAUSE TestPartSizeForNAR/small_stays_at_minimum287=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum288=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum289=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts290=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts291=== RUN TestPartSizeForNAR/1_TiB2922026/10/06 10:42:35 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50293=== PAUSE TestPartSizeForNAR/1_TiB294=== CONT TestSetClientTLSErrors/missing_cert_file295=== CONT TestSetClientTLSErrors/invalid_ca_file2962026/10/06 10:42:35 WARN Rate limiter backed off name=server-test rate=5297=== CONT TestSetClientTLSErrors/missing_ca_file298=== CONT TestSetClientTLSErrors/missing_key_file299=== CONT TestGetStorePathHash/valid_store_path300=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA301=== CONT TestParsePathInfoJSON/Nix_format302=== CONT TestUploadMultipart_SupersededByPeer/exists303=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error304=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error305=== CONT TestGetStorePathHash/basename_without_hyphen_should_error306=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512307=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI308=== CONT TestFilterOversizedClosures/no_limit_keeps_everything309=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon310=== CONT TestParsePathInfoJSON/invalid_JSON311=== CONT TestParsePathInfoJSON/whitespace_only312=== CONT TestParsePathInfoJSON/Lix_format313=== CONT TestConvertHashToNix32/SRI_format_to_Nix32314=== CONT TestConvertHashToNix32/invalid_format315=== CONT TestConvertHashToNix32/already_Nix32_format316=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)317=== CONT TestUploadMultipart_SupersededByPeer/missing318--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)319=== CONT TestParsePathInfoJSON/empty_input320=== RUN TestPartSizeForNAR/5_TiB_S3_max_object321=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object322--- PASS: TestRateLimiterFeedback (0.07s)323 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)326 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)327--- PASS: TestScriptTokenCachesUntilRefresh (0.08s)328=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method329=== CONT TestPathInfoCACompatibility/new_structured_format_-_text330=== CONT TestPathInfoCACompatibility/old_string_format_-_text331=== CONT TestSetClientTLS/preserves_debug_logging_transport332=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped333=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive334=== CONT TestPathInfoCACompatibility/null_ca_field335=== RUN TestPartSizeForNAR/capped_at_5_GiB336--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)3372026/10/06 10:42:35 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=2000338--- PASS: TestParsePathInfoJSON (0.07s)339 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)341 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)342 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)343 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)344=== PAUSE TestPartSizeForNAR/capped_at_5_GiB345=== CONT TestPartSizeForNAR/zero_stays_at_minimum346=== CONT TestPartSizeForNAR/1_TiB347=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts348=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum349=== CONT TestPartSizeForNAR/small_stays_at_minimum350=== CONT TestPartSizeForNAR/capped_at_5_GiB351--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)352 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)353 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)354=== CONT TestPartSizeForNAR/5_TiB_S3_max_object355--- PASS: TestSetClientTLSErrors (0.08s)356 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)357 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)358 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)359 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)360--- PASS: TestGetStorePathHash (0.07s)361 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)362 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)363 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)364 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)365--- PASS: TestConvertHashToNix32 (0.07s)366 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)367 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)368 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)369--- PASS: TestPathInfoHashCompatibility (0.07s)370 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)371 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)372 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)373 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)374--- PASS: TestPathInfoCACompatibility (0.07s)375 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)376 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)377 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)378 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)379 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)380--- PASS: TestFilterOversizedClosures (0.07s)381 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)382 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)383 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)384--- PASS: TestPartSizeForNAR (0.01s)385 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)386 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)387 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)388 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)389 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)390 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)391 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)392--- PASS: TestStreamPushRequestLine (0.02s)3932026/10/06 10:42:35 http: TLS handshake error from 127.0.0.1:47192: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.07s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)399--- PASS: TestCaseHackSuffix (0.03s)400--- PASS: TestDumpPathSingleFile (0.03s)401--- PASS: TestStreamPushBatchesUnderLoad (0.12s)402--- PASS: TestDumpPathWriterError (0.05s)403--- PASS: TestDumpPathMatchesNix (0.09s)404--- PASS: TestUploadMultipart_PartsInParallel (0.68s)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/postgres554567254/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/postgres554567254/data -l logfile start434435/build/postgres554567254:5432 - no response4362026-10-06 10:42:37.408 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 10:42:37.409 UTC [130] LOG: listening on Unix socket "/build/postgres554567254/.s.PGSQL.5432"4382026-10-06 10:42:37.414 UTC [137] LOG: database system was shut down at 2026-10-06 10:42:37 UTC4392026-10-06 10:42:37.418 UTC [130] LOG: database system is ready to accept connections440/build/postgres554567254:5432 - accepting connections441{"timestamp":"2026-10-06T10:42:37.717484129Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"992a96f9-59b9-4018-a16a-189abe38a8c0","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(389)"}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 10:42:37 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 10:42:38 INFO lead: released remote=192.0.2.1:12344892026/10/06 10:42:38 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 10:42:39 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 10:42:39 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 10:42:41.239 UTC [576] FATAL: terminating connection due to administrator command4992026/10/06 10:42:41 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 10:42:42 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 10:42:42 INFO lead: released remote=192.0.2.1:12345022026/10/06 10:42:42 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.93s)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 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:42:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 10:42:42 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 TestParseSize694--- PASS: TestParseSize (0.00s)695=== CONT TestFailedS3DeleteKeepsTombstone696=== CONT TestPresentNotReportedWhileGCDeletesClosure697=== CONT TestCompleteMultipartUnregistered698=== CONT TestService_verifyS3Integrity699=== CONT TestService_createPendingClosureHandler700=== CONT TestService_cleanupPendingClosuresHandler701=== CONT TestUploadHandlersRejectOversizedBody702=== CONT TestUploadHandlersRejectInvalidKeys703=== CONT TestIsValidUploadKey704=== RUN TestIsValidUploadKey/narinfo705=== CONT TestPendingClosureWriteTimeout706=== CONT TestProxyWriteTimeout707=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle708=== CONT TestSkippedUploadsHandler709=== CONT TestPresentReportsOnlyClosureRoots710=== CONT TestCreatePin_ReservedPins711=== CONT TestOrphanedObjectsGCStressTest712=== CONT TestOrphanedObjectsGC713=== CONT TestObjectStatsTrigger714=== CONT TestPendingCleanupUsesOneCutoff715=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded716=== CONT TestMultipartCleanup717=== CONT TestServerTLSConfig718=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT719=== RUN TestProxyWriteTimeout/narinfo720=== PAUSE TestProxyWriteTimeout/narinfo721=== RUN TestProxyWriteTimeout/1_GiB_nar722=== PAUSE TestProxyWriteTimeout/1_GiB_nar723=== RUN TestProxyWriteTimeout/10_GiB_nar724=== PAUSE TestProxyWriteTimeout/10_GiB_nar725=== RUN TestProxyWriteTimeout/unknown_size726=== PAUSE TestProxyWriteTimeout/unknown_size727=== RUN TestServerTLSConfig/no_client_CA728=== RUN TestPendingClosureWriteTimeout/empty729=== PAUSE TestIsValidUploadKey/narinfo730=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info7312026/10/06 10:42:42 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000732=== RUN TestIsValidUploadKey/nar_zst733=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info734=== CONT TestService_NativeMTLS735=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal736=== PAUSE TestServerTLSConfig/no_client_CA737=== RUN TestServerTLSConfig/missing_CA_file738=== PAUSE TestServerTLSConfig/missing_CA_file739=== RUN TestServerTLSConfig/not_a_PEM_file740=== PAUSE TestServerTLSConfig/not_a_PEM_file741=== PAUSE TestIsValidUploadKey/nar_zst742=== CONT TestMetricsInventory743=== RUN TestIsValidUploadKey/nar_xz744=== PAUSE TestIsValidUploadKey/nar_xz745=== RUN TestIsValidUploadKey/nar_plain746=== PAUSE TestIsValidUploadKey/nar_plain747=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal748=== PAUSE TestPendingClosureWriteTimeout/empty7492026/10/06 10:42:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46713/oidc750=== RUN TestIsValidUploadKey/listing751=== PAUSE TestIsValidUploadKey/listing752=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key753=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key754=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key755=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key756=== RUN TestPendingClosureWriteTimeout/400_objects757=== PAUSE TestPendingClosureWriteTimeout/400_objects758=== RUN TestPendingClosureWriteTimeout/670k_objects759=== PAUSE TestPendingClosureWriteTimeout/670k_objects760=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline761=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline762=== RUN TestIsValidUploadKey/build_log763=== PAUSE TestIsValidUploadKey/build_log764=== RUN TestIsValidUploadKey/build_log_home-manager_file765=== PAUSE TestIsValidUploadKey/build_log_home-manager_file766=== RUN TestIsValidUploadKey/build_log_plus_in_name767=== PAUSE TestIsValidUploadKey/build_log_plus_in_name768=== RUN TestIsValidUploadKey/build_log_question_mark769=== PAUSE TestIsValidUploadKey/build_log_question_mark770=== RUN TestIsValidUploadKey/build_log_equals771=== PAUSE TestIsValidUploadKey/build_log_equals772=== RUN TestIsValidUploadKey/realisation773=== PAUSE TestIsValidUploadKey/realisation774=== RUN TestIsValidUploadKey/realisation_plus_in_output775=== PAUSE TestIsValidUploadKey/realisation_plus_in_output776=== CONT TestNARDeduplicationMetadataUploadBug777=== CONT TestCreatePendingClosureRejectsOversizedNAR778=== RUN TestIsValidUploadKey/nix-cache-info779=== PAUSE TestIsValidUploadKey/nix-cache-info780=== RUN TestIsValidUploadKey/index.html781=== PAUSE TestIsValidUploadKey/index.html7822026/10/06 10:42:42 INFO Received uploads request method=POST path=/api/pending_closures783=== RUN TestIsValidUploadKey/narinfo_key,_nar_type784=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type785=== RUN TestIsValidUploadKey/nar_key,_narinfo_type786=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type787=== RUN TestIsValidUploadKey/listing_key,_narinfo_type788=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type789=== RUN TestIsValidUploadKey/traversal790=== PAUSE TestIsValidUploadKey/traversal791=== RUN TestIsValidUploadKey/traversal_nar792=== PAUSE TestIsValidUploadKey/traversal_nar793=== RUN TestIsValidUploadKey/absolute794--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)795=== CONT TestCacheConfigHandlerMaxNarSize796=== PAUSE TestIsValidUploadKey/absolute797--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)798=== CONT TestGenerateLandingPage799=== RUN TestIsValidUploadKey/empty_key800=== PAUSE TestIsValidUploadKey/empty_key801=== RUN TestIsValidUploadKey/unknown_type802=== PAUSE TestIsValidUploadKey/unknown_type803=== CONT TestService_readinessHandler804--- PASS: TestSkippedUploadsHandler (0.07s)805=== CONT TestService_healthCheckHandler806--- PASS: TestGenerateLandingPage (0.01s)807=== CONT TestGracefulShutdownDrainsInflight8082026/10/06 10:42:42 INFO Starting HTTP server address=127.0.0.1:352338092026/10/06 10:42:42 INFO Shutdown signal received, draining in-flight requests timeout=10s810=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure811=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure812=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart813=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart814=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts815=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts816=== CONT TestGCTaskStore_Fail817--- PASS: TestGCTaskStore_Fail (0.00s)818=== CONT TestGCTaskStore_PhaseUpdates819--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)820=== CONT TestGCTaskStore_CompletedAllowsNewTask821--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)822=== CONT TestGCTaskStore_GetReturnsLatest823--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)824=== CONT TestGCTaskStore_GetEmpty825--- PASS: TestGCTaskStore_GetEmpty (0.00s)826=== CONT TestGCTaskStore_ConflictDifferentParams827--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)828=== CONT TestGCTaskStore_DeduplicateSameParams829--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)830=== CONT TestGCTaskStore_StartNew831--- PASS: TestGCTaskStore_StartNew (0.00s)832=== CONT TestGCEndsOnShutdown833=== RUN TestGCEndsOnShutdown/before_the_run834=== PAUSE TestGCEndsOnShutdown/before_the_run835=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete836=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete837=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark838=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark839=== CONT TestCommitRacingPendingCleanupKeepsObjects840--- PASS: TestGracefulShutdownDrainsInflight (0.07s)841=== CONT TestPushWaitsForSweepHoldingRow8422026/10/06 10:42:43 INFO Received cleanup request method=DELETE path=/api/pending_closures8432026/10/06 10:42:43 INFO Aborted multipart uploads count=0 kept=08442026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8452026/10/06 10:42:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8462026/10/06 10:42:43 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst847--- PASS: TestCompleteMultipartUnregistered (0.39s)848=== CONT TestSweepRechecksPendingAfterLocking8492026/10/06 10:42:43 INFO Received cleanup request method=DELETE path=/api/pending_closures8502026/10/06 10:42:43 INFO Aborted multipart uploads count=1 kept=08512026/10/06 10:42:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8522026-10-06 10:42:43.275 UTC [646] ERROR: Closure does not exist: id=18532026-10-06 10:42:43.275 UTC [646] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8542026-10-06 10:42:43.275 UTC [646] STATEMENT: -- name: CommitPendingClosure :exec855 SELECT commit_pending_closure($1::bigint)856 857--- PASS: TestService_cleanupPendingClosuresHandler (0.40s)858=== CONT TestGetExistingObjectsLocksRows8592026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/06 10:42:43 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"861--- PASS: TestService_AuthMiddleware (0.43s)862=== CONT TestRegisterCompletedObjectNeedsPendingRow8632026/10/06 10:42:43 INFO Aborted multipart uploads count=0 kept=08642026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8652026/10/06 10:42:43 WARN Force mode enabled - objects will be deleted immediately without grace period8662026/10/06 10:42:43 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8672026/10/06 10:42:43 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."868--- PASS: TestFailedS3DeleteKeepsTombstone (0.51s)869=== CONT TestSweepSkipsRowsLockedByPush870--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.50s)871=== CONT TestReadRedirectNar8722026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8732026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8742026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8762026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8772026/10/06 10:42:43 INFO Received cleanup request method=DELETE path=/api/pending_closures8782026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures879--- PASS: TestObjectStatsTrigger (0.65s)880=== CONT TestService_Rustfstest881--- PASS: TestPresentReportsOnlyClosureRoots (0.67s)882=== CONT TestPresignedUploadRegisteredBeforeCommit8832026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures8842026/10/06 10:42:43 INFO Received cleanup request method=DELETE path=/api/pending_closures8852026/10/06 10:42:43 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8862026/10/06 10:42:43 INFO Aborted multipart uploads count=0 kept=1887--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.69s)888=== CONT TestCompletedNarNotReofferedAcrossClosures8892026/10/06 10:42:43 INFO Received cleanup request method=DELETE path=/api/pending_closures8902026/10/06 10:42:43 INFO Aborted multipart uploads count=1 kept=0891--- PASS: TestMultipartCleanup (0.70s)892=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8932026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures894--- PASS: TestMetricsInventory (0.72s)895=== CONT TestRedundantMultipartUpload896=== NAME TestOrphanedObjectsGC897 orphaned_objects_gc_test.go:290: GC Test Summary:898 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A899 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B900 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)901 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)902 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects903--- PASS: TestOrphanedObjectsGC (0.88s)904=== CONT TestPush_SignsNarinfosOfItsPendingObjects9052026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures9062026/10/06 10:42:43 INFO Aborted multipart uploads count=0 kept=09072026/10/06 10:42:43 WARN Force mode enabled - objects will be deleted immediately without grace period9082026/10/06 10:42:43 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=09092026/10/06 10:42:43 INFO Vacuumed table table=pending_closures9102026/10/06 10:42:43 INFO Vacuumed table table=pending_objects9112026/10/06 10:42:43 INFO Vacuumed table table=multipart_uploads9122026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures9132026/10/06 10:42:43 INFO Vacuumed table table=closures9142026/10/06 10:42:43 INFO Vacuumed table table=objects915--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.79s)916=== CONT TestPush_RejectsBadRequests9172026/10/06 10:42:43 WARN readiness check failed error="closed pool"918--- PASS: TestService_readinessHandler (0.89s)919=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9202026/10/06 10:42:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete921=== NAME TestNARDeduplicationMetadataUploadBug922 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3593211257/001/store/v1bz0pf0znj2clkdfxw8qv9zyapz3jng-file1.txt9232026/10/06 10:42:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9242026/10/06 10:42:43 WARN Refused reserved pin name=worker-x86_64-linux9252026/10/06 10:42:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9262026/10/06 10:42:43 INFO Received create pin request method=POST path=/api/pins/my-app9272026/10/06 10:42:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux928--- PASS: TestCreatePin_ReservedPins (0.99s)929=== CONT TestPush_CompleteCommitsEveryRoot9302026/10/06 10:42:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9312026/10/06 10:42:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"932--- PASS: TestService_NativeMTLS (0.94s)933=== CONT TestPush_OverlappingRootsStoreOneRowPerKey934--- PASS: TestService_healthCheckHandler (0.95s)935=== CONT TestReadRedirectUsesPublicS3URL936--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.05s)937=== CONT TestReadProxyRangeRequest9382026/10/06 10:42:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9392026/10/06 10:42:43 INFO Aborted multipart uploads count=0 kept=09402026/10/06 10:42:43 INFO Received push request method=POST path=/api/pushes9412026/10/06 10:42:43 WARN Force mode enabled - objects will be deleted immediately without grace period9422026/10/06 10:42:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9432026/10/06 10:42:43 INFO Uploading v1bz0pf0znj2clkdfxw8qv9zyapz3jng-file1.txt (160B)944--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.65s)945=== CONT TestReadRedirectKeepsNarinfoProxied9462026/10/06 10:42:43 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9472026/10/06 10:42:43 WARN Failed to register uploaded object key=v1bz0pf0znj2clkdfxw8qv9zyapz3jng.ls error="server returned 404: 404 page not found\n"9482026/10/06 10:42:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9492026/10/06 10:42:43 INFO Signed narinfos id=1 count=19502026/10/06 10:42:43 INFO Uploading 1 narinfos9512026/10/06 10:42:43 INFO Received complete push request method=POST path=/api/pushes/1/complete9522026/10/06 10:42:43 WARN Failed to register uploaded object key=v1bz0pf0znj2clkdfxw8qv9zyapz3jng.narinfo error="server returned 404: 404 page not found\n"9532026/10/06 10:42:43 INFO Upload complete. (73ms)9542026/10/06 10:42:43 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLmNlNGY5NTdjLTg1ZWUtNGQ0Yy1iMTFjLTg3ZjM2MDIzMTJkOHgxNzkxMjgzMzYzNDk2ODc1Mjk5 parts=10955=== NAME TestNARDeduplicationMetadataUploadBug9562026/10/06 10:42:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete957 metadata_upload_test.go:54: Retrieved narinfo from S3:958 StorePath: /build/TestNARDeduplicationMetadataUploadBug3593211257/001/store/v1bz0pf0znj2clkdfxw8qv9zyapz3jng-file1.txt959 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst960 Compression: zstd961 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf962 NarSize: 160963 References: 964 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf965 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)966 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):967 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9682026/10/06 10:42:43 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=09692026/10/06 10:42:43 INFO Completed upload id=19702026/10/06 10:42:43 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009712026/10/06 10:42:43 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/06 10:42:43 INFO Vacuumed table table=pending_closures9732026/10/06 10:42:43 INFO Vacuumed table table=pending_objects9742026/10/06 10:42:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures9752026/10/06 10:42:43 INFO Vacuumed table table=multipart_uploads9762026/10/06 10:42:43 INFO Vacuumed table table=closures977--- PASS: TestGetExistingObjectsLocksRows (0.72s)978=== CONT TestClientFallsBackToClosures9792026/10/06 10:42:43 INFO Vacuumed table table=objects980--- PASS: TestSweepRechecksPendingAfterLocking (0.74s)981=== CONT TestForceGCDuringPushOffersSweptObject982=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows983=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows984=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check985=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check986=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9872026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=09882026/10/06 10:42:44 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=09892026/10/06 10:42:44 INFO Vacuumed table table=pending_closures9902026/10/06 10:42:44 INFO Vacuumed table table=pending_objects9912026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=09922026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period993=== NAME TestNARDeduplicationMetadataUploadBug994 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3593211257/001/store/x4wy76y1kdhjd1bmssjcw145grs1p9rf-file2.txt9952026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads9962026/10/06 10:42:44 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=0997--- PASS: TestReadRedirectNar (0.64s)998=== CONT TestGCSweepDeliversEachKeyOnce9992026/10/06 10:42:44 INFO Vacuumed table table=pending_closures10002026/10/06 10:42:44 INFO Vacuumed table table=pending_objects10012026/10/06 10:42:44 INFO Vacuumed table table=closures10022026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads10032026/10/06 10:42:44 INFO Vacuumed table table=closures10042026/10/06 10:42:44 INFO Vacuumed table table=objects10052026/10/06 10:42:44 INFO Vacuumed table table=objects10062026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=010072026/10/06 10:42:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10082026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period1009--- PASS: TestService_Rustfstest (0.51s)1010=== CONT TestTombstonedObjectOfferedWithoutWaiting10112026/10/06 10:42:44 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001012--- PASS: TestService_createPendingClosureHandler (1.17s)1013=== CONT TestGCSweepSkipsPendingObjects10142026/10/06 10:42:44 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=010152026/10/06 10:42:44 INFO Vacuumed table table=pending_closures10162026/10/06 10:42:44 INFO Vacuumed table table=pending_objects10172026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads10182026/10/06 10:42:44 INFO Vacuumed table table=closures10192026/10/06 10:42:44 INFO Vacuumed table table=objects1020--- PASS: TestSweepSkipsRowsLockedByPush (0.67s)1021=== CONT TestDeduplicatedObjectsRecordedAsPending10222026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures10232026/10/06 10:42:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLmFjMDE2MDY4LTYwN2YtNGM0Ni05YTMyLThjYzk0NDVjNjg0M3gxNzkxMjgzMzYzNTk4NjA2NDMz parts=1010242026/10/06 10:42:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10252026/10/06 10:42:44 INFO Completed upload id=110262026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures10272026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures10282026/10/06 10:42:44 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10292026/10/06 10:42:44 WARN Found objects in DB but missing from S3, will re-upload count=11030--- PASS: TestService_verifyS3Integrity (1.21s)1031=== CONT TestPushDedupSurvivesConcurrentGC10322026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/06 10:42:44 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10342026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures10352026/10/06 10:42:44 INFO Received push request method=POST path=/api/pushes1036--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.55s)1037=== CONT TestGCMetrics10382026/10/06 10:42:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10392026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10402026/10/06 10:42:44 WARN Failed to register uploaded object key=x4wy76y1kdhjd1bmssjcw145grs1p9rf.ls error="server returned 404: 404 page not found\n"10412026/10/06 10:42:44 INFO Signed narinfos id=2 count=110422026/10/06 10:42:44 INFO Uploading 1 narinfos10432026/10/06 10:42:44 INFO Received complete push request method=POST path=/api/pushes/2/complete10442026/10/06 10:42:44 WARN Failed to register uploaded object key=x4wy76y1kdhjd1bmssjcw145grs1p9rf.narinfo error="server returned 404: 404 page not found\n"10452026/10/06 10:42:44 INFO Upload complete. (54ms)1046=== NAME TestNARDeduplicationMetadataUploadBug1047 metadata_upload_test.go:76: Retrieved narinfo from S3:1048 StorePath: /build/TestNARDeduplicationMetadataUploadBug3593211257/001/store/x4wy76y1kdhjd1bmssjcw145grs1p9rf-file2.txt10492026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures1050 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1051 Compression: zstd1052 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1053 NarSize: 1601054 References: 1055 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1056 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1057 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1058 {"version":1,"root":{"type":"regular","size":44}}1059--- PASS: TestNARDeduplicationMetadataUploadBug (1.17s)1060=== CONT TestGCBugBareHashReferences10612026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures10622026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures10632026/10/06 10:42:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10642026/10/06 10:42:44 INFO Received push request method=POST path=/api/pushes10652026/10/06 10:42:44 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLmYyMjUxYWZmLTk2ZDUtNDc4OS04MTMxLWIwMGQ2MTdiODFlNHgxNzkxMjgzMzY0MTM0MzgyMDIx10662026/10/06 10:42:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLmYyMjUxYWZmLTk2ZDUtNDc4OS04MTMxLWIwMGQ2MTdiODFlNHgxNzkxMjgzMzY0MTM0MzgyMDIx parts=11067--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.60s)1068=== CONT TestGCAdvisoryLockBlocksConcurrentRun1069=== RUN TestPush_RejectsBadRequests/no_roots1070=== PAUSE TestPush_RejectsBadRequests/no_roots1071=== RUN TestPush_RejectsBadRequests/no_objects1072=== PAUSE TestPush_RejectsBadRequests/no_objects1073=== RUN TestPush_RejectsBadRequests/bad_root1074=== PAUSE TestPush_RejectsBadRequests/bad_root1075=== RUN TestPush_RejectsBadRequests/root_not_in_objects1076=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1077=== CONT TestLeadEndsOnShutdown10782026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10792026/10/06 10:42:44 INFO Signed narinfos id=1 count=110802026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10812026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10822026/10/06 10:42:44 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10832026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10842026/10/06 10:42:44 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10852026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10862026/10/06 10:42:44 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110872026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10882026/10/06 10:42:44 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1089--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.45s)1090=== CONT TestLeadIncumbentAnnouncesAtOnce10912026/10/06 10:42:44 INFO Received push request method=POST path=/api/pushes10922026/10/06 10:42:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10932026/10/06 10:42:44 INFO Received push request method=POST path=/api/pushes10942026/10/06 10:42:44 INFO Received push request method=POST path=/api/pushes10952026/10/06 10:42:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10962026/10/06 10:42:44 INFO Received push request method=POST path=/api/pushes1097--- PASS: TestPush_CompleteCommitsEveryRoot (0.43s)1098=== CONT TestLeadElectsOneAndHandsOver1099--- PASS: TestPushWaitsForSweepHoldingRow (1.28s)1100=== CONT TestConnectWaitsForAPeerMigration11012026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=01102--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.44s)1103=== CONT TestResolveDBConnectionString1104=== RUN TestResolveDBConnectionString/flag_wins1105=== PAUSE TestResolveDBConnectionString/flag_wins1106=== RUN TestResolveDBConnectionString/file_when_flag_empty1107=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1108=== RUN TestResolveDBConnectionString/missing_file_is_an_error1109=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1110=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1111=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1112=== RUN TestResolveDBConnectionString/nothing_configured1113=== PAUSE TestResolveDBConnectionString/nothing_configured1114=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11152026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period1116--- PASS: TestReadRedirectUsesPublicS3URL (0.43s)1117=== CONT TestReadProxy40411182026/10/06 10:42:44 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=011192026/10/06 10:42:44 INFO Vacuumed table table=pending_closures11202026/10/06 10:42:44 INFO Vacuumed table table=pending_objects1121--- PASS: TestReadProxyRangeRequest (0.43s)1122=== CONT TestReadProxyDisabled11232026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads11242026/10/06 10:42:44 INFO Vacuumed table table=closures11252026/10/06 10:42:44 INFO Vacuumed table table=objects11262026/10/06 10:42:44 INFO Received complete push request method=POST path=/api/pushes/2/complete1127--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.54s)1128=== CONT TestReadProxyRootRedirectsToIndexHTML1129--- PASS: TestReadRedirectKeepsNarinfoProxied (0.43s)1130=== CONT TestReadProxyConditionalGet11312026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures11322026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures1133--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.47s)1134=== CONT TestReadProxyInvalidPath11352026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=011362026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period11372026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures11382026/10/06 10:42:44 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=011392026/10/06 10:42:44 INFO Vacuumed table table=pending_closures11402026/10/06 10:42:44 INFO Vacuumed table table=pending_objects1141--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.49s)11422026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads1143=== CONT TestReadProxyNarinfo11442026/10/06 10:42:44 INFO Vacuumed table table=closures11452026/10/06 10:42:44 INFO Vacuumed table table=objects1146--- PASS: TestGCSweepDeliversEachKeyOnce (0.53s)1147=== CONT TestReadProxyNarStreaming11482026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures11492026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures11502026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures11512026/10/06 10:42:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11522026/10/06 10:42:44 INFO Uploading hz6cacfw4mw0x63csbrqi9f53bxyyszj-a (216B)11532026/10/06 10:42:44 INFO Uploading 22bh0q9f5y589fp0dz1znxq5zg9zfni2-shared-dep (136B)11542026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=011552026/10/06 10:42:44 WARN Failed to register uploaded object key=f44920rg101697hcgxgryn8z7shz09zz.ls error="server returned 404: 404 page not found\n"11562026/10/06 10:42:44 WARN Failed to register uploaded object key=nar/1m421zd5sb3588sxkgx71cp236hh2yqvmz044lgq4dwyhr9230xy.nar.zst error="server returned 404: 404 page not found\n"11572026/10/06 10:42:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11582026/10/06 10:42:44 WARN Failed to register uploaded object key=hz6cacfw4mw0x63csbrqi9f53bxyyszj.ls error="server returned 404: 404 page not found\n"11592026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11602026/10/06 10:42:44 WARN Failed to register uploaded object key=22bh0q9f5y589fp0dz1znxq5zg9zfni2.ls error="server returned 404: 404 page not found\n"11612026/10/06 10:42:44 INFO Signed narinfos id=1 count=211622026/10/06 10:42:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11632026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period11642026/10/06 10:42:44 INFO Signed narinfos id=2 count=211652026/10/06 10:42:44 INFO Uploading 4 narinfos11662026/10/06 10:42:44 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=011672026/10/06 10:42:44 WARN Failed to register uploaded object key=hz6cacfw4mw0x63csbrqi9f53bxyyszj.narinfo error="server returned 404: 404 page not found\n"11682026/10/06 10:42:44 WARN Failed to register uploaded object key=22bh0q9f5y589fp0dz1znxq5zg9zfni2.narinfo error="server returned 404: 404 page not found\n"11692026/10/06 10:42:44 WARN Failed to register uploaded object key=f44920rg101697hcgxgryn8z7shz09zz.narinfo error="server returned 404: 404 page not found\n"11702026/10/06 10:42:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11712026/10/06 10:42:44 WARN Failed to register uploaded object key=22bh0q9f5y589fp0dz1znxq5zg9zfni2.narinfo error="server returned 404: 404 page not found\n"11722026/10/06 10:42:44 INFO Vacuumed table table=pending_closures11732026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=011742026/10/06 10:42:44 INFO Vacuumed table table=pending_objects11752026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads11762026/10/06 10:42:44 INFO Vacuumed table table=closures11772026/10/06 10:42:44 INFO Vacuumed table table=objects11782026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period11792026/10/06 10:42:44 INFO Completed upload id=111802026/10/06 10:42:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11812026/10/06 10:42:44 INFO Completed upload id=211822026/10/06 10:42:44 INFO Upload complete. (72ms)11832026/10/06 10:42:44 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=01184=== NAME TestClientFallsBackToClosures1185 client_pushes_test.go:112: Retrieved narinfo from S3:1186 StorePath: /build/TestClientFallsBackToClosures3213415732/001/store/22bh0q9f5y589fp0dz1znxq5zg9zfni2-shared-dep1187 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1188 Compression: zstd1189 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821190 NarSize: 1361191 References: 1192 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11932026/10/06 10:42:44 INFO Vacuumed table table=pending_closures11942026/10/06 10:42:44 INFO Vacuumed table table=pending_objects11952026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads11962026/10/06 10:42:44 INFO Vacuumed table table=closures11972026/10/06 10:42:44 INFO Vacuumed table table=objects1198 client_pushes_test.go:112: Retrieved narinfo from S3:1199 StorePath: /build/TestClientFallsBackToClosures3213415732/001/store/hz6cacfw4mw0x63csbrqi9f53bxyyszj-a1200 URL: nar/1m421zd5sb3588sxkgx71cp236hh2yqvmz044lgq4dwyhr9230xy.nar.zst1201 Compression: zstd1202 NarHash: sha256:1m421zd5sb3588sxkgx71cp236hh2yqvmz044lgq4dwyhr9230xy1203 NarSize: 2161204 References: /build/TestClientFallsBackToClosures3213415732/001/store/22bh0q9f5y589fp0dz1znxq5zg9zfni2-shared-dep1205 CA: text:sha256:1lgawh4bs5jwmqsdvdmy4di8z5wnrghaygvsbmk46ikf98phmw0b1206--- PASS: TestGCSweepSkipsPendingObjects (0.60s)1207=== CONT TestReadProxyContentNegotiation1208=== NAME TestClientFallsBackToClosures1209 client_pushes_test.go:112: Retrieved narinfo from S3:1210 StorePath: /build/TestClientFallsBackToClosures3213415732/001/store/f44920rg101697hcgxgryn8z7shz09zz-b1211 URL: nar/1m421zd5sb3588sxkgx71cp236hh2yqvmz044lgq4dwyhr9230xy.nar.zst1212 Compression: zstd1213 NarHash: sha256:1m421zd5sb3588sxkgx71cp236hh2yqvmz044lgq4dwyhr9230xy1214 NarSize: 2161215 References: /build/TestClientFallsBackToClosures3213415732/001/store/22bh0q9f5y589fp0dz1znxq5zg9zfni2-shared-dep1216 CA: text:sha256:1lgawh4bs5jwmqsdvdmy4di8z5wnrghaygvsbmk46ikf98phmw0b1217--- PASS: TestGCMetrics (0.55s)1218=== CONT TestReadProxyNarinfoAlreadyDecompressed1219--- PASS: TestClientFallsBackToClosures (0.65s)1220=== CONT TestProxyHeadersOnlyTrustedOnSocket12212026/10/06 10:42:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1222--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.66s)1223=== CONT TestIsValidCachePath1224=== RUN TestIsValidCachePath/narinfo1225=== PAUSE TestIsValidCachePath/narinfo1226=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1227=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1228=== RUN TestIsValidCachePath/nar_zst1229=== PAUSE TestIsValidCachePath/nar_zst1230=== RUN TestIsValidCachePath/nar_xz1231=== PAUSE TestIsValidCachePath/nar_xz1232=== RUN TestIsValidCachePath/nar_bz21233=== PAUSE TestIsValidCachePath/nar_bz21234=== RUN TestIsValidCachePath/nar_uncompressed1235=== PAUSE TestIsValidCachePath/nar_uncompressed1236=== RUN TestIsValidCachePath/ls1237=== PAUSE TestIsValidCachePath/ls1238=== RUN TestIsValidCachePath/log1239=== PAUSE TestIsValidCachePath/log1240=== RUN TestIsValidCachePath/realisation1241=== PAUSE TestIsValidCachePath/realisation1242=== RUN TestIsValidCachePath/nix-cache-info1243=== PAUSE TestIsValidCachePath/nix-cache-info1244=== RUN TestIsValidCachePath/index.html1245=== PAUSE TestIsValidCachePath/index.html1246=== RUN TestIsValidCachePath/traversal_parent1247=== PAUSE TestIsValidCachePath/traversal_parent1248=== RUN TestIsValidCachePath/traversal_in_middle1249=== PAUSE TestIsValidCachePath/traversal_in_middle1250=== RUN TestIsValidCachePath/invalid_char_e1251=== PAUSE TestIsValidCachePath/invalid_char_e1252=== RUN TestIsValidCachePath/invalid_char_u1253=== PAUSE TestIsValidCachePath/invalid_char_u1254=== RUN TestIsValidCachePath/random_path1255=== PAUSE TestIsValidCachePath/random_path1256=== RUN TestIsValidCachePath/empty1257=== PAUSE TestIsValidCachePath/empty1258=== RUN TestIsValidCachePath/leading_slash1259=== PAUSE TestIsValidCachePath/leading_slash1260=== RUN TestIsValidCachePath/wrong_extension1261=== PAUSE TestIsValidCachePath/wrong_extension1262=== RUN TestIsValidCachePath/short_hash1263=== PAUSE TestIsValidCachePath/short_hash1264=== CONT TestParseSingleRange1265=== RUN TestParseSingleRange/none1266=== PAUSE TestParseSingleRange/none1267=== RUN TestParseSingleRange/unknown_unit1268=== PAUSE TestParseSingleRange/unknown_unit1269=== RUN TestParseSingleRange/multi-range_ignored1270=== PAUSE TestParseSingleRange/multi-range_ignored1271=== RUN TestParseSingleRange/malformed_no_dash1272=== PAUSE TestParseSingleRange/malformed_no_dash1273=== RUN TestParseSingleRange/malformed_both_empty1274=== PAUSE TestParseSingleRange/malformed_both_empty1275=== RUN TestParseSingleRange/malformed_end_before_start1276=== PAUSE TestParseSingleRange/malformed_end_before_start1277=== RUN TestParseSingleRange/closed1278=== PAUSE TestParseSingleRange/closed1279=== RUN TestParseSingleRange/open-ended1280=== PAUSE TestParseSingleRange/open-ended1281=== RUN TestParseSingleRange/end_clamped_to_size1282=== PAUSE TestParseSingleRange/end_clamped_to_size1283=== RUN TestParseSingleRange/suffix1284=== PAUSE TestParseSingleRange/suffix1285=== RUN TestParseSingleRange/suffix_exceeds_size1286=== PAUSE TestParseSingleRange/suffix_exceeds_size1287=== RUN TestParseSingleRange/single_byte1288=== PAUSE TestParseSingleRange/single_byte1289=== RUN TestParseSingleRange/start_past_EOF1290=== PAUSE TestParseSingleRange/start_past_EOF1291=== RUN TestParseSingleRange/start_far_past_EOF1292=== PAUSE TestParseSingleRange/start_far_past_EOF1293=== CONT TestClientCADerivations12942026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures12952026/10/06 10:42:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLmM4NmZjNzkxLTk0NjYtNGY5Zi1hNjc1LTBmNGU0MGY4NzBjZXgxNzkxMjgzMzY0MDk5NjczNzE1 parts=1212962026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures12972026/10/06 10:42:44 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"1298--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.52s)1299=== CONT TestClientPushesUseOnePush1300--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.13s)1301=== CONT TestPinProtectsFromGC13022026/10/06 10:42:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13032026/10/06 10:42:44 INFO lead: acquired remote=192.0.2.1:123413042026/10/06 10:42:44 INFO lead: released remote=192.0.2.1:12341305--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.52s)1306=== CONT TestClientSharedPathCommittedMidPush13072026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=013082026/10/06 10:42:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLjM3ODU5YTdjLTcxNzUtNDdhMi04YzM1LWMxMWU1M2I4ZjQyOHgxNzkxMjgzMzY0MTUyMDQwNjg0 parts=1213092026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures13102026/10/06 10:42:44 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=013112026/10/06 10:42:44 INFO lead: acquired remote=192.0.2.1:123413122026/10/06 10:42:44 INFO Vacuumed table table=pending_closures13132026/10/06 10:42:44 INFO Received uploads request method=POST path=/api/pending_closures13142026/10/06 10:42:44 INFO Vacuumed table table=pending_objects13152026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads13162026/10/06 10:42:44 INFO lead: acquired remote=192.0.2.1:123413172026/10/06 10:42:44 INFO Vacuumed table table=closures13182026/10/06 10:42:44 INFO Vacuumed table table=objects13192026/10/06 10:42:44 INFO Aborted multipart uploads count=0 kept=013202026/10/06 10:42:44 WARN Force mode enabled - objects will be deleted immediately without grace period13212026/10/06 10:42:44 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=013222026/10/06 10:42:44 INFO Vacuumed table table=pending_closures13232026/10/06 10:42:44 INFO Vacuumed table table=pending_objects13242026/10/06 10:42:44 INFO Vacuumed table table=multipart_uploads13252026/10/06 10:42:44 INFO Vacuumed table table=closures13262026/10/06 10:42:44 INFO Vacuumed table table=objects1327--- PASS: TestPushDedupSurvivesConcurrentGC (0.71s)1328=== CONT TestClientWithDependencies1329--- PASS: TestReadProxy404 (0.49s)1330=== CONT TestClientMultipleUploads1331--- PASS: TestReadProxyDisabled (0.49s)1332=== CONT TestClientIntegration1333--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.50s)1334=== CONT TestClientErrorHandling1335=== RUN TestClientErrorHandling/InvalidStorePath1336=== PAUSE TestClientErrorHandling/InvalidStorePath1337=== RUN TestClientErrorHandling/InvalidAuthToken1338=== PAUSE TestClientErrorHandling/InvalidAuthToken1339=== RUN TestClientErrorHandling/ServerNotAvailable1340=== PAUSE TestClientErrorHandling/ServerNotAvailable1341=== CONT TestService_RequireScope_OIDC1342--- PASS: TestReadProxyConditionalGet (0.51s)1343=== CONT TestCacheStatsHandler1344--- PASS: TestReadProxyInvalidPath (0.40s)1345=== CONT TestCacheConfigHandler1346=== RUN TestCacheConfigHandler/full_config,_no_issuer1347=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1348=== RUN TestCacheConfigHandler/no_cache_url_configured1349=== PAUSE TestCacheConfigHandler/no_cache_url_configured1350=== RUN TestCacheConfigHandler/no_signing_keys1351=== PAUSE TestCacheConfigHandler/no_signing_keys1352=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1353=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1354=== CONT TestService_ReadScope_PublicByDefault1355--- PASS: TestGCBugBareHashReferences (0.80s)1356=== CONT TestService_ReadAuthMiddleware13572026/10/06 10:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40545/oidc1358--- PASS: TestReadProxyNarStreaming (0.42s)1359=== CONT TestService_AuthMiddleware_OIDC13602026/10/06 10:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34761/oidc13612026/10/06 10:42:45 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1362--- PASS: TestReadProxyNarinfo (0.48s)1363=== CONT TestReadProxyOutlastsServerWriteTimeout1364--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.39s)1365=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1366--- PASS: TestReadProxyContentNegotiation (0.41s)1367=== CONT TestService_AuthMiddleware_MTLSProxyHeader13682026/10/06 10:42:45 INFO Starting HTTP server address=127.0.0.1:3398913692026/10/06 10:42:45 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2935481211/001/proxy.sock13702026/10/06 10:42:45 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13712026/10/06 10:42:45 INFO Shutdown signal received, draining in-flight requests timeout=10s1372--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.41s)1373=== CONT TestReadProxyHead1374--- PASS: TestService_ReadAuthMiddleware (0.20s)1375=== CONT TestProxyWriteTimeout/narinfo1376=== CONT TestProxyWriteTimeout/unknown_size1377=== CONT TestProxyWriteTimeout/10_GiB_nar1378=== CONT TestProxyWriteTimeout/1_GiB_nar1379--- PASS: TestProxyWriteTimeout (0.00s)1380 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1381 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1382 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1383 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1384=== CONT TestServerTLSConfig/no_client_CA1385=== CONT TestServerTLSConfig/not_a_PEM_file1386=== CONT TestServerTLSConfig/missing_CA_file1387--- PASS: TestServerTLSConfig (0.07s)1388 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1389 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1390 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1391=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13922026/10/06 10:42:45 INFO Received uploads request method=POST path=/1393=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13942026/10/06 10:42:45 INFO Received complete multipart upload request method=POST path=/1395=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13962026/10/06 10:42:45 INFO Received uploads request method=POST path=/1397=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13982026/10/06 10:42:45 INFO Received request for more parts method=POST path=/1399--- PASS: TestUploadHandlersRejectInvalidKeys (0.07s)1400 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1401 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1402 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1403 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1404=== CONT TestPendingClosureWriteTimeout/empty1405=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1406--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.85s)1407=== CONT TestPendingClosureWriteTimeout/670k_objects1408=== CONT TestPendingClosureWriteTimeout/400_objects1409=== CONT TestIsValidUploadKey/narinfo1410=== CONT TestIsValidUploadKey/traversal1411=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1412=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1413=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1414=== CONT TestIsValidUploadKey/index.html1415=== CONT TestIsValidUploadKey/nix-cache-info1416=== CONT TestIsValidUploadKey/realisation_plus_in_output1417=== CONT TestIsValidUploadKey/realisation1418=== CONT TestIsValidUploadKey/build_log_equals1419=== CONT TestIsValidUploadKey/build_log_question_mark1420=== CONT TestIsValidUploadKey/build_log_plus_in_name1421=== CONT TestIsValidUploadKey/build_log_home-manager_file1422=== CONT TestIsValidUploadKey/build_log1423=== CONT TestIsValidUploadKey/listing1424=== CONT TestIsValidUploadKey/nar_plain1425=== CONT TestIsValidUploadKey/nar_xz1426=== CONT TestIsValidUploadKey/nar_zst1427=== CONT TestIsValidUploadKey/empty_key1428=== CONT TestIsValidUploadKey/unknown_type1429=== CONT TestIsValidUploadKey/absolute1430=== CONT TestIsValidUploadKey/traversal_nar1431--- PASS: TestIsValidUploadKey (0.07s)1432 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1433 --- PASS: TestIsValidUploadKey/traversal (0.00s)1434 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1435 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1436 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1437 --- PASS: TestIsValidUploadKey/index.html (0.00s)1438 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1439 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1440 --- PASS: TestIsValidUploadKey/realisation (0.00s)1441 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1442 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1443 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1444 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1445 --- PASS: TestIsValidUploadKey/build_log (0.00s)1446 --- PASS: TestIsValidUploadKey/listing (0.00s)1447 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1448 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1449 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1450 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1451 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1452 --- PASS: TestIsValidUploadKey/absolute (0.00s)1453 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1454=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14552026/10/06 10:42:45 INFO Received uploads request method=POST path=/1456=== NAME TestClientCADerivations1457 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1610283922/001/store/fr84nm2k3bqmg4fb3j8dv3qdcywr84pr-ca-test1458 client_ca_test.go:139: Found 1 dependencies (including self)1459=== NAME TestOrphanedObjectsGCStressTest1460 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1461=== NAME TestPinProtectsFromGC1462 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4165695826/001/store/v2bbfnl3im4iq8js5dcxbmk3s7rjib6c-pinned-file.txt1463 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4165695826/001/store/q66nxidgzxkgisik0m6hmmly96ln1mkw-unpinned-file.txt1464=== NAME TestOrphanedObjectsGCStressTest1465 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion14662026/10/06 10:42:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14672026/10/06 10:42:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLmJiZmFiZmVmLTEzNDItNGQwMy1hYjQwLTIyODg2YzE0YjI1MHgxNzkxMjgzMzY0NzY5NjM5OTY2 error="Get \"http://127.0.0.1:1/bucket36/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14682026/10/06 10:42:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTE2ZTA0NmQtODljMS00MGEwLWI3NWItYzNmNmQ0NjdjNTUwLmQ4MWFjYTY4LTFhN2MtNGU5Ni05MDBiLTM5MDRiMmE4MGQzMHgxNzkxMjgzMzY0NzQ0NjM0Mzk5 parts=1214692026/10/06 10:42:45 INFO Received cleanup request method=DELETE path=/api/pending_closures14702026/10/06 10:42:45 INFO Aborted multipart uploads count=1 kept=01471--- PASS: TestRedundantMultipartUpload (1.64s)1472=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14732026/10/06 10:42:45 INFO Received request for more parts method=POST path=/1474=== NAME TestClientMultipleUploads1475 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3325744695/001/store/90k463zzkq4skx3rd66q8r4yp47fbcqv-test-file-0.txt1476--- PASS: TestService_ReadScope_PublicByDefault (0.40s)1477=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14782026/10/06 10:42:45 INFO Received complete multipart upload request method=POST path=/1479=== NAME TestClientWithDependencies1480 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2124733291/001/store/ms5badgcvjv3cmhxvdaipwvvs88bx3j3-test-script14812026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes14822026/10/06 10:42:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14832026/10/06 10:42:45 INFO Uploading v2bbfnl3im4iq8js5dcxbmk3s7rjib6c-pinned-file.txt (128B)14842026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14852026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14862026/10/06 10:42:45 INFO Signed narinfos id=1 count=114872026/10/06 10:42:45 WARN Failed to register uploaded object key=v2bbfnl3im4iq8js5dcxbmk3s7rjib6c.ls error="server returned 404: 404 page not found\n"14882026/10/06 10:42:45 INFO Uploading 1 narinfos14892026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/1/complete14902026/10/06 10:42:45 WARN Failed to register uploaded object key=v2bbfnl3im4iq8js5dcxbmk3s7rjib6c.narinfo error="server returned 404: 404 page not found\n"1491=== NAME TestClientIntegration1492 client_integration_test.go:286: Created store path: /build/TestClientIntegration937097743/002/store/cfn26468in1qllhn45jabsngzpz51q3f-test-file.txt14932026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes14942026/10/06 10:42:45 INFO Upload complete. (64ms)14952026/10/06 10:42:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14962026/10/06 10:42:45 INFO Uploading fr84nm2k3bqmg4fb3j8dv3qdcywr84pr-ca-test (144B)14972026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1498=== NAME TestClientMultipleUploads14992026/10/06 10:42:45 WARN Failed to register uploaded object key=log/k765f0ikxgdysilrl2nwvayndab530v4-ca-test.drv error="server returned 404: 404 page not found\n"1500 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3325744695/001/store/iqn5c8d7akvq50xhmxmysw9653ws65v7-test-file-1.txt15012026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15022026/10/06 10:42:45 WARN Failed to register uploaded object key=fr84nm2k3bqmg4fb3j8dv3qdcywr84pr.ls error="server returned 404: 404 page not found\n"15032026/10/06 10:42:45 INFO Signed narinfos id=1 count=115042026/10/06 10:42:45 INFO Uploading 1 narinfos1505--- PASS: TestCacheStatsHandler (0.46s)1506=== CONT TestGCEndsOnShutdown/before_the_run15072026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15082026/10/06 10:42:45 WARN Failed to register uploaded object key=fr84nm2k3bqmg4fb3j8dv3qdcywr84pr.narinfo error="server returned 404: 404 page not found\n"1509=== NAME TestClientWithDependencies1510 client_integration_test.go:615: Found 1 dependencies (including self)1511=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15122026/10/06 10:42:45 INFO Upload complete. (104ms)1513=== NAME TestClientCADerivations1514 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1610283922/001/store/fr84nm2k3bqmg4fb3j8dv3qdcywr84pr-ca-test1515 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst15162026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes1517 Compression: zstd1518 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1519 NarSize: 1441520 References: 1521 Deriver: /build/TestClientCADerivations1610283922/001/store/k765f0ikxgdysilrl2nwvayndab530v4-ca-test.drv1522 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1523 client_ca_test.go:185: Checking for realisation files in S3...1524 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1525 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15262026/10/06 10:42:45 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15272026/10/06 10:42:45 INFO Uploading lc6jpb002xaq8w3w9qbwgk9qhrrwiw0p-top (224B)15282026/10/06 10:42:45 INFO Uploading f55a208v21sqw6q0ql5kspdyy0gnkygg-shared-dep (136B)1529=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1530=== NAME TestClientMultipleUploads1531 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3325744695/001/store/6pjdhz4srcyl47i1dazb1a32s554mk33-test-file-2.txt15322026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/00yh53n891zarsilf6qfzh9rbzjsvql5nmlb2mw869h70hm0fvin.nar.zst error="server returned 404: 404 page not found\n"15332026/10/06 10:42:45 WARN Failed to register uploaded object key=lc6jpb002xaq8w3w9qbwgk9qhrrwiw0p.ls error="server returned 404: 404 page not found\n"15342026/10/06 10:42:45 WARN Failed to register uploaded object key=f55a208v21sqw6q0ql5kspdyy0gnkygg.ls error="server returned 404: 404 page not found\n"15352026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15362026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15372026/10/06 10:42:45 INFO Signed narinfos id=1 count=215382026/10/06 10:42:45 INFO Uploading 2 narinfos15392026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes1540=== RUN TestService_RequireScope_OIDC/builder_may_write1541=== PAUSE TestService_RequireScope_OIDC/builder_may_write1542=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1543=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1544=== RUN TestService_RequireScope_OIDC/ops_may_admin1545=== PAUSE TestService_RequireScope_OIDC/ops_may_admin15462026/10/06 10:42:45 WARN Failed to register uploaded object key=f55a208v21sqw6q0ql5kspdyy0gnkygg.narinfo error="server returned 404: 404 page not found\n"1547=== RUN TestService_RequireScope_OIDC/ops_may_not_write15482026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/1/complete1549=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write15502026/10/06 10:42:45 WARN Failed to register uploaded object key=lc6jpb002xaq8w3w9qbwgk9qhrrwiw0p.narinfo error="server returned 404: 404 page not found\n"1551=== RUN TestService_RequireScope_OIDC/reader_may_not_write1552=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1553=== RUN TestService_RequireScope_OIDC/static_token_may_admin1554=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1555=== RUN TestService_RequireScope_OIDC/static_token_may_write1556=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1557=== RUN TestService_RequireScope_OIDC/reader_may_read1558=== PAUSE TestService_RequireScope_OIDC/reader_may_read1559=== RUN TestService_RequireScope_OIDC/writer_implies_read1560=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1561=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1562=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1563=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1564=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1565=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1566=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1567=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1568=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1569=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1570=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1571=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1572=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1573=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1574=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1575=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1576=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1577=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1578=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1579=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1580=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15812026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes15822026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes15832026/10/06 10:42:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15842026/10/06 10:42:45 INFO Uploading ffgcailrhljmivq1sidayrgp7rkk01y6-b (208B)15852026/10/06 10:42:45 INFO Uploading 7i6axikz84nj4zn7vy1kyba0zg0589hj-shared-dep (136B)15862026/10/06 10:42:45 INFO Upload complete. (84ms)1587=== NAME TestClientSharedPathCommittedMidPush1588 client_integration_test.go:680: Retrieved narinfo from S3:1589 StorePath: /build/TestClientSharedPathCommittedMidPush1812277674/001/store/f55a208v21sqw6q0ql5kspdyy0gnkygg-shared-dep1590 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1591 Compression: zstd1592 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821593 NarSize: 1361594 References: 1595 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15962026/10/06 10:42:45 WARN Failed to register uploaded object key=ac7h2g03jmhi93bi0py39cah9pb5i6nh.ls error="server returned 404: 404 page not found\n"15972026/10/06 10:42:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15982026/10/06 10:42:45 INFO Uploading q66nxidgzxkgisik0m6hmmly96ln1mkw-unpinned-file.txt (128B)15992026/10/06 10:42:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16002026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/00bn8akkpfhavhrn8jfbnddzx7yk7gndr9lpij92lcbdbrvs358q.nar.zst error="server returned 404: 404 page not found\n"16012026/10/06 10:42:45 INFO Uploading cfn26468in1qllhn45jabsngzpz51q3f-test-file.txt (152B)16022026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16032026/10/06 10:42:45 WARN Failed to register uploaded object key=7i6axikz84nj4zn7vy1kyba0zg0589hj.ls error="server returned 404: 404 page not found\n"16042026/10/06 10:42:45 WARN Failed to register uploaded object key=ffgcailrhljmivq1sidayrgp7rkk01y6.ls error="server returned 404: 404 page not found\n"16052026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1606 client_integration_test.go:680: Retrieved narinfo from S3:1607 StorePath: /build/TestClientSharedPathCommittedMidPush1812277674/001/store/lc6jpb002xaq8w3w9qbwgk9qhrrwiw0p-top1608 URL: nar/00yh53n891zarsilf6qfzh9rbzjsvql5nmlb2mw869h70hm0fvin.nar.zst1609 Compression: zstd1610 NarHash: sha256:00yh53n891zarsilf6qfzh9rbzjsvql5nmlb2mw869h70hm0fvin1611 NarSize: 2241612 References: /build/TestClientSharedPathCommittedMidPush1812277674/001/store/f55a208v21sqw6q0ql5kspdyy0gnkygg-shared-dep1613 CA: text:sha256:1pss1hgc4r4fyxfxc8fvprjnw5anryc3p3bpfbihd1dwhqxinjqs16142026/10/06 10:42:45 INFO Signed narinfos id=1 count=316152026/10/06 10:42:45 INFO Uploading 3 narinfos16162026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16172026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16182026/10/06 10:42:45 INFO Signed narinfos id=2 count=116192026/10/06 10:42:45 WARN Failed to register uploaded object key=q66nxidgzxkgisik0m6hmmly96ln1mkw.ls error="server returned 404: 404 page not found\n"16202026/10/06 10:42:45 INFO Uploading 1 narinfos16212026/10/06 10:42:45 WARN Failed to register uploaded object key=cfn26468in1qllhn45jabsngzpz51q3f.ls error="server returned 404: 404 page not found\n"16222026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16232026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16242026/10/06 10:42:45 WARN Failed to register uploaded object key=ac7h2g03jmhi93bi0py39cah9pb5i6nh.narinfo error="server returned 404: 404 page not found\n"1625--- PASS: TestClientSharedPathCommittedMidPush (0.70s)16262026/10/06 10:42:45 INFO Signed narinfos id=1 count=11627=== CONT TestPush_RejectsBadRequests/no_roots16282026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes16292026/10/06 10:42:45 INFO Uploading 1 narinfos1630=== CONT TestPush_RejectsBadRequests/bad_root16312026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes1632=== CONT TestPush_RejectsBadRequests/no_objects16332026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes1634=== CONT TestPush_RejectsBadRequests/root_not_in_objects16352026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes1636=== CONT TestResolveDBConnectionString/flag_wins1637=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1638--- PASS: TestPush_RejectsBadRequests (0.39s)1639 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1640 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1641 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1642 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1643=== CONT TestResolveDBConnectionString/nothing_configured1644=== CONT TestResolveDBConnectionString/missing_file_is_an_error1645=== CONT TestResolveDBConnectionString/file_when_flag_empty1646=== CONT TestIsValidCachePath/narinfo1647=== CONT TestIsValidCachePath/invalid_char_e1648=== CONT TestIsValidCachePath/traversal_in_middle1649=== CONT TestIsValidCachePath/traversal_parent1650=== CONT TestIsValidCachePath/index.html1651=== CONT TestIsValidCachePath/invalid_char_u16522026/10/06 10:42:45 WARN Failed to register uploaded object key=7i6axikz84nj4zn7vy1kyba0zg0589hj.narinfo error="server returned 404: 404 page not found\n"1653=== CONT TestIsValidCachePath/nix-cache-info16542026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/1/complete1655=== CONT TestIsValidCachePath/realisation1656=== CONT TestIsValidCachePath/log16572026/10/06 10:42:45 WARN Failed to register uploaded object key=ffgcailrhljmivq1sidayrgp7rkk01y6.narinfo error="server returned 404: 404 page not found\n"1658=== CONT TestIsValidCachePath/ls1659=== CONT TestIsValidCachePath/nar_uncompressed1660=== CONT TestIsValidCachePath/nar_zst1661=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1662=== CONT TestIsValidCachePath/leading_slash1663=== CONT TestIsValidCachePath/short_hash1664=== CONT TestIsValidCachePath/wrong_extension1665=== CONT TestIsValidCachePath/empty1666=== CONT TestIsValidCachePath/random_path1667=== CONT TestIsValidCachePath/nar_xz1668=== CONT TestIsValidCachePath/nar_bz21669=== CONT TestParseSingleRange/none1670=== CONT TestParseSingleRange/start_past_EOF1671=== CONT TestParseSingleRange/single_byte1672=== CONT TestParseSingleRange/suffix_exceeds_size1673=== CONT TestParseSingleRange/suffix1674=== CONT TestParseSingleRange/end_clamped_to_size1675=== CONT TestParseSingleRange/start_far_past_EOF1676=== CONT TestParseSingleRange/open-ended1677=== CONT TestParseSingleRange/closed16782026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/2/complete1679--- PASS: TestResolveDBConnectionString (0.00s)1680 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1681 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1682 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1683 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1684 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16852026/10/06 10:42:45 WARN Failed to register uploaded object key=q66nxidgzxkgisik0m6hmmly96ln1mkw.narinfo error="server returned 404: 404 page not found\n"1686=== CONT TestParseSingleRange/malformed_end_before_start1687=== CONT TestParseSingleRange/malformed_both_empty1688=== CONT TestParseSingleRange/malformed_no_dash1689=== CONT TestParseSingleRange/multi-range_ignored1690=== CONT TestParseSingleRange/unknown_unit1691=== CONT TestClientErrorHandling/InvalidStorePath1692--- PASS: TestIsValidCachePath (0.00s)1693 --- PASS: TestIsValidCachePath/narinfo (0.00s)1694 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1695 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1696 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1697 --- PASS: TestIsValidCachePath/index.html (0.00s)1698 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1699 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1700 --- PASS: TestIsValidCachePath/realisation (0.00s)1701 --- PASS: TestIsValidCachePath/log (0.00s)1702 --- PASS: TestIsValidCachePath/ls (0.00s)1703 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1704 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1705 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1706 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1707 --- PASS: TestIsValidCachePath/short_hash (0.00s)1708 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1709 --- PASS: TestIsValidCachePath/empty (0.00s)1710 --- PASS: TestIsValidCachePath/random_path (0.00s)1711 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1712 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)17132026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/1/complete1714--- PASS: TestParseSingleRange (0.00s)1715 --- PASS: TestParseSingleRange/none (0.00s)1716 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1717 --- PASS: TestParseSingleRange/single_byte (0.00s)1718 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1719 --- PASS: TestParseSingleRange/suffix (0.00s)1720 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1721 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1722 --- PASS: TestParseSingleRange/open-ended (0.00s)1723 --- PASS: TestParseSingleRange/closed (0.00s)1724 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1725 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1726 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1727 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1728 --- PASS: TestParseSingleRange/unknown_unit (0.00s)17292026/10/06 10:42:45 WARN Failed to register uploaded object key=cfn26468in1qllhn45jabsngzpz51q3f.narinfo error="server returned 404: 404 page not found\n"17302026/10/06 10:42:45 INFO Upload complete. (52ms)17312026/10/06 10:42:45 INFO Upload complete. (62ms)17322026/10/06 10:42:45 INFO Upload complete. (87ms)1733=== NAME TestClientPushesUseOnePush1734 client_pushes_test.go:97: Retrieved narinfo from S3:1735 StorePath: /build/TestClientPushesUseOnePush996583322/001/store/7i6axikz84nj4zn7vy1kyba0zg0589hj-shared-dep1736 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1737 Compression: zstd1738 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821739 NarSize: 1361740 References: 1741 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17422026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes1743 client_pushes_test.go:97: Retrieved narinfo from S3:1744 StorePath: /build/TestClientPushesUseOnePush996583322/001/store/ac7h2g03jmhi93bi0py39cah9pb5i6nh-a1745 URL: nar/00bn8akkpfhavhrn8jfbnddzx7yk7gndr9lpij92lcbdbrvs358q.nar.zst1746 Compression: zstd1747 NarHash: sha256:00bn8akkpfhavhrn8jfbnddzx7yk7gndr9lpij92lcbdbrvs358q1748 NarSize: 2081749 References: /build/TestClientPushesUseOnePush996583322/001/store/7i6axikz84nj4zn7vy1kyba0zg0589hj-shared-dep1750 CA: text:sha256:190p95ihy20h37bsprs6202viq0dajdv1z25iz212i7k6ghzknj31751 client_pushes_test.go:97: Retrieved narinfo from S3:1752 StorePath: /build/TestClientPushesUseOnePush996583322/001/store/ffgcailrhljmivq1sidayrgp7rkk01y6-b1753 URL: nar/00bn8akkpfhavhrn8jfbnddzx7yk7gndr9lpij92lcbdbrvs358q.nar.zst1754 Compression: zstd1755 NarHash: sha256:00bn8akkpfhavhrn8jfbnddzx7yk7gndr9lpij92lcbdbrvs358q1756 NarSize: 2081757 References: /build/TestClientPushesUseOnePush996583322/001/store/7i6axikz84nj4zn7vy1kyba0zg0589hj-shared-dep1758 CA: text:sha256:190p95ihy20h37bsprs6202viq0dajdv1z25iz212i7k6ghzknj317592026/10/06 10:42:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1760--- PASS: TestClientPushesUseOnePush (0.74s)17612026/10/06 10:42:45 INFO Uploading ms5badgcvjv3cmhxvdaipwvvs88bx3j3-test-script (136B)1762=== CONT TestClientErrorHandling/ServerNotAvailable17632026/10/06 10:42:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17642026/10/06 10:42:45 WARN mTLS auth: bound subjects configured but subject DN unavailable17652026/10/06 10:42:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1766--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.41s)1767=== CONT TestClientErrorHandling/InvalidAuthToken17682026/10/06 10:42:45 WARN Failed to register uploaded object key=ms5badgcvjv3cmhxvdaipwvvs88bx3j3.ls error="server returned 404: 404 page not found\n"17692026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17702026/10/06 10:42:45 WARN Failed to register uploaded object key=log/c8wy609sfskfz3nsk6ibw4akzn8ffa28-test-script.drv error="server returned 404: 404 page not found\n"17712026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17722026/10/06 10:42:45 INFO Signed narinfos id=1 count=117732026/10/06 10:42:45 INFO Uploading 1 narinfos17742026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/1/complete17752026/10/06 10:42:45 WARN Failed to register uploaded object key=ms5badgcvjv3cmhxvdaipwvvs88bx3j3.narinfo error="server returned 404: 404 page not found\n"17762026/10/06 10:42:45 INFO Upload complete. (62ms)17772026/10/06 10:42:45 INFO Received push request method=POST path=/api/pushes1778=== NAME TestClientWithDependencies1779 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2124733291/001/store) requires matching store prefix1780--- PASS: TestClientWithDependencies (0.67s)17812026/10/06 10:42:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures1782=== CONT TestCacheConfigHandler/full_config,_no_issuer1783=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator17842026/10/06 10:42:45 INFO Garbage collection started1785=== CONT TestCacheConfigHandler/no_cache_url_configured1786=== CONT TestService_RequireScope_OIDC/builder_may_write1787--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.42s)1788=== CONT TestCacheConfigHandler/no_signing_keys1789--- PASS: TestCacheConfigHandler (0.00s)1790 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1791 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1792 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1793 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1794=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17952026/10/06 10:42:45 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]1796=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc17972026/10/06 10:42:45 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1798=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc17992026/10/06 10:42:45 INFO Uploading 90k463zzkq4skx3rd66q8r4yp47fbcqv-test-file-0.txt (160B)1800=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read18012026/10/06 10:42:45 INFO Uploading 6pjdhz4srcyl47i1dazb1a32s554mk33-test-file-2.txt (160B)1802=== CONT TestService_RequireScope_OIDC/writer_implies_read18032026/10/06 10:42:45 INFO Uploading iqn5c8d7akvq50xhmxmysw9653ws65v7-test-file-1.txt (160B)1804=== CONT TestService_RequireScope_OIDC/reader_may_read1805=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1806=== CONT TestService_RequireScope_OIDC/static_token_may_write1807=== CONT TestService_RequireScope_OIDC/static_token_may_admin1808=== CONT TestService_RequireScope_OIDC/ops_may_not_write1809=== CONT TestService_RequireScope_OIDC/reader_may_not_write1810=== CONT TestService_RequireScope_OIDC/ops_may_admin18112026/10/06 10:42:45 INFO All 1 paths already cached1812=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1813=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1814=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18152026/10/06 10:42:45 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]1816=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1817=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1818=== NAME TestClientIntegration1819 client_integration_test.go:312: Retrieved narinfo from S3:1820 StorePath: /build/TestClientIntegration937097743/002/store/cfn26468in1qllhn45jabsngzpz51q3f-test-file.txt1821 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1822 Compression: zstd1823 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11824 NarSize: 1521825 References: 1826 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11827--- PASS: TestService_RequireScope_OIDC (0.52s)1828 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1829 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1830 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1831 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18422026/10/06 10:42:45 WARN Failed to register uploaded object key=90k463zzkq4skx3rd66q8r4yp47fbcqv.ls error="server returned 404: 404 page not found\n"18432026/10/06 10:42:45 WARN Authentication failed token_preview=eyJhbGciOi...2nx4kS1PJw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]18442026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18452026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18462026/10/06 10:42:45 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1847=== NAME TestClientIntegration1848 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)18492026/10/06 10:42:45 WARN Failed to register uploaded object key=6pjdhz4srcyl47i1dazb1a32s554mk33.ls error="server returned 404: 404 page not found\n"1850 client_integration_test.go:313: Decompressed .ls content (64 bytes):18512026/10/06 10:42:45 WARN Failed to register uploaded object key=iqn5c8d7akvq50xhmxmysw9653ws65v7.ls error="server returned 404: 404 page not found\n"1852 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}18532026/10/06 10:42:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1854--- PASS: TestService_AuthMiddleware_OIDC (0.42s)1855 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1856 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1857 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1858 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1859=== NAME TestClientIntegration1860 client_integration_test.go:316: Testing garbage collection...18612026/10/06 10:42:45 INFO Signed narinfos id=1 count=318622026/10/06 10:42:45 INFO Uploading 3 narinfos18632026/10/06 10:42:45 WARN Failed to register uploaded object key=6pjdhz4srcyl47i1dazb1a32s554mk33.narinfo error="server returned 404: 404 page not found\n"18642026/10/06 10:42:45 WARN Failed to register uploaded object key=90k463zzkq4skx3rd66q8r4yp47fbcqv.narinfo error="server returned 404: 404 page not found\n"18652026/10/06 10:42:45 INFO Received complete push request method=POST path=/api/pushes/1/complete18662026/10/06 10:42:45 WARN Failed to register uploaded object key=iqn5c8d7akvq50xhmxmysw9653ws65v7.narinfo error="server returned 404: 404 page not found\n"18672026/10/06 10:42:45 INFO Aborted multipart uploads count=0 kept=018682026/10/06 10:42:45 WARN Force mode enabled - objects will be deleted immediately without grace period18692026/10/06 10:42:45 INFO Upload complete. (75ms)1870=== NAME TestClientMultipleUploads1871 client_integration_test.go:369: Uploaded 3 paths in 111.684861ms1872=== NAME TestClientCADerivations1873 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1874 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1875 error: binary cache 's3://bucket69?endpoint=http://localhost:37153®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1610283922/001/store'1876 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 118772026/10/06 10:42:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures18782026/10/06 10:42:45 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/present18792026/10/06 10:42:45 INFO Received uploads request method=POST path=/api/pending_closures18802026/10/06 10:42:45 INFO Garbage collection started1881--- PASS: TestClientCADerivations (0.93s)1882--- PASS: TestReadProxyHead (0.53s)18832026/10/06 10:42:45 INFO Aborted multipart uploads count=0 kept=01884--- PASS: TestClientMultipleUploads (0.78s)18852026/10/06 10:42:45 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=018862026/10/06 10:42:45 WARN Force mode enabled - objects will be deleted immediately without grace period18872026/10/06 10:42:45 INFO Vacuumed table table=pending_closures18882026/10/06 10:42:45 INFO Vacuumed table table=pending_objects18892026/10/06 10:42:45 INFO Vacuumed table table=multipart_uploads18902026/10/06 10:42:45 INFO Vacuumed table table=closures18912026/10/06 10:42:45 INFO Vacuumed table table=objects18922026/10/06 10:42:45 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=018932026/10/06 10:42:45 INFO Vacuumed table table=pending_closures18942026/10/06 10:42:45 INFO Vacuumed table table=pending_objects18952026/10/06 10:42:45 INFO Vacuumed table table=multipart_uploads18962026/10/06 10:42:45 INFO Vacuumed table table=closures18972026/10/06 10:42:45 INFO Vacuumed table table=objects1898=== NAME TestOrphanedObjectsGCStressTest1899 orphaned_objects_gc_test.go:509: Stress test completed successfully:1900 orphaned_objects_gc_test.go:510: - Active objects preserved: 201901 orphaned_objects_gc_test.go:511: - Objects deleted: 2101902 orphaned_objects_gc_test.go:512: - Total GC'd: 2101903--- PASS: TestOrphanedObjectsGCStressTest (2.75s)19042026/10/06 10:42:45 INFO Aborted multipart uploads count=0 kept=019052026/10/06 10:42:45 WARN Force mode enabled - objects will be deleted immediately without grace period19062026/10/06 10:42:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.373926ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19072026/10/06 10:42:45 INFO Received uploads request method=POST path=/api/pending_closures19082026/10/06 10:42:45 INFO Aborted multipart uploads count=0 kept=019092026/10/06 10:42:45 WARN Force mode enabled - objects will be deleted immediately without grace period19102026/10/06 10:42:45 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=019112026/10/06 10:42:45 INFO Vacuumed table table=pending_closures19122026/10/06 10:42:45 INFO Vacuumed table table=pending_objects19132026/10/06 10:42:45 INFO Vacuumed table table=multipart_uploads19142026/10/06 10:42:45 INFO Vacuumed table table=closures19152026/10/06 10:42:45 INFO Vacuumed table table=objects19162026/10/06 10:42:45 INFO Aborted multipart uploads count=0 kept=019172026/10/06 10:42:45 WARN Force mode enabled - objects will be deleted immediately without grace period19182026/10/06 10:42:45 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37153/bucket91/?delete=\": context canceled"1919--- PASS: TestGCEndsOnShutdown (0.00s)1920 --- PASS: TestGCEndsOnShutdown/before_the_run (0.28s)1921 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.31s)1922 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.39s)19232026/10/06 10:42:45 INFO Received uploads request method=POST path=/api/pending_closures19242026/10/06 10:42:45 INFO Aborted multipart uploads count=0 kept=019252026/10/06 10:42:45 WARN Force mode enabled - objects will be deleted immediately without grace period19262026/10/06 10:42:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19272026/10/06 10:42:45 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=019282026/10/06 10:42:45 INFO Vacuumed table table=pending_closures19292026/10/06 10:42:45 INFO Vacuumed table table=pending_objects19302026/10/06 10:42:45 INFO Vacuumed table table=multipart_uploads19312026/10/06 10:42:45 INFO Vacuumed table table=closures19322026/10/06 10:42:45 INFO lead: released remote=192.0.2.1:12341933--- PASS: TestLeadEndsOnShutdown (1.60s)19342026/10/06 10:42:45 INFO Vacuumed table table=objects1935--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1936 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)1937 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.43s)19382026/10/06 10:42:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1939--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1940 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1941 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)1942 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)19432026/10/06 10:42:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.748276ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19442026/10/06 10:42:45 INFO lead: released remote=192.0.2.1:123419452026/10/06 10:42:46 INFO lead: acquired remote=192.0.2.1:123419462026/10/06 10:42:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=721.485321ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1947--- PASS: TestPendingClosureWriteTimeout (0.07s)1948 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1949 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1950 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1951 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.27s)19522026/10/06 10:42:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.648256249s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19532026/10/06 10:42:47 INFO lead: released remote=192.0.2.1:12341954--- PASS: TestLeadElectsOneAndHandsOver (2.82s)19552026/10/06 10:42:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019562026/10/06 10:42:47 INFO Received create pin request method=POST path=/api/pins/myapp19572026/10/06 10:42:47 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4165695826/001/store/v2bbfnl3im4iq8js5dcxbmk3s7rjib6c-pinned-file.txt narinfo_key=v2bbfnl3im4iq8js5dcxbmk3s7rjib6c.narinfo19582026/10/06 10:42:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures19592026/10/06 10:42:47 INFO Garbage collection started19602026/10/06 10:42:47 INFO Aborted multipart uploads count=0 kept=019612026/10/06 10:42:47 WARN Force mode enabled - objects will be deleted immediately without grace period19622026/10/06 10:42:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019632026/10/06 10:42:47 INFO Vacuumed table table=pending_closures19642026/10/06 10:42:47 INFO Vacuumed table table=pending_objects19652026/10/06 10:42:47 INFO Vacuumed table table=multipart_uploads19662026/10/06 10:42:47 INFO Vacuumed table table=closures19672026/10/06 10:42:47 INFO Vacuumed table table=objects19682026/10/06 10:42:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01969=== NAME TestClientIntegration1970 client_integration_test.go:323: Objects in database after GC:1971 client_integration_test.go:323: Successfully deleted all objects with GC --force1972--- PASS: TestClientIntegration (2.75s)19732026/10/06 10:42:48 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-config19742026/10/06 10:42:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.929698ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19752026/10/06 10:42:48 WARN Rate limiter enabled after throttle name=s3-test rate=519762026/10/06 10:42:48 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1977=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1978 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101979 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001980--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.11s)19812026/10/06 10:42:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.686098ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19822026/10/06 10:42:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=841.190126ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1983=== NAME TestPinProtectsFromGC1984 client_integration_test.go:840: Pin successfully protected closure from garbage collection1985--- PASS: TestConnectWaitsForAPeerMigration (5.18s)19862026/10/06 10:42:49 INFO Aborted multipart uploads count=1 kept=01987--- PASS: TestPinProtectsFromGC (4.79s)19882026/10/06 10:42:49 INFO Received cleanup request method=DELETE path=/api/pending_closures19892026/10/06 10:42:49 INFO Aborted multipart uploads count=1 kept=01990--- PASS: TestPendingCleanupUsesOneCutoff (6.63s)1991--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.61s)19922026/10/06 10:42:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.492207446s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19932026/10/06 10:42:51 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"19942026/10/06 10:42:51 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-config19952026/10/06 10:42:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.118961ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19962026/10/06 10:42:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.594433ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19972026/10/06 10:42:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=814.281604ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19982026/10/06 10:42:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.647896537s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19992026/10/06 10:42:54 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_closures20002026/10/06 10:42:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.718822ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20012026/10/06 10:42:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.86875ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20022026/10/06 10:42:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=740.847561ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20032026/10/06 10:42:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.522455909s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2004--- PASS: TestClientErrorHandling (0.00s)2005 --- PASS: TestClientErrorHandling/InvalidStorePath (0.28s)2006 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)2007 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.38s)2008PASS20092026-10-06 10:42:58.167 UTC [130] LOG: received smart shutdown request20102026-10-06 10:42:58.172 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 120112026-10-06 10:42:58.186 UTC [135] LOG: shutting down20122026-10-06 10:42:58.186 UTC [135] LOG: checkpoint starting: shutdown immediate20132026-10-06 10:43:00.033 UTC [135] LOG: checkpoint complete: wrote 11001 buffers (67.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.280 s, sync=1.512 s, total=1.848 s; sync files=31336, longest=0.013 s, average=0.001 s; distance=433015 kB, estimate=433015 kB; lsn=0/1BE43940, redo lsn=0/1BE4394020142026-10-06 10:43:00.110 UTC [130] LOG: database system is shut down2015Running OIDC tests...2016=== RUN TestAudienceForIssuer2017=== PAUSE TestAudienceForIssuer2018=== RUN TestGlobMatch2019=== PAUSE TestGlobMatch2020=== RUN TestValidateToken_ValidToken2021=== PAUSE TestValidateToken_ValidToken2022=== RUN TestValidateToken_WrongAudience2023=== PAUSE TestValidateToken_WrongAudience2024=== RUN TestValidateToken_Expired2025=== PAUSE TestValidateToken_Expired2026=== RUN TestValidateToken_BoundClaimsMismatch2027=== PAUSE TestValidateToken_BoundClaimsMismatch2028=== RUN TestValidateToken_BoundSubjectMismatch2029=== PAUSE TestValidateToken_BoundSubjectMismatch2030=== RUN TestValidateToken_MultipleProviders2031=== PAUSE TestValidateToken_MultipleProviders2032=== RUN TestValidateToken_NoMatchingProvider2033=== PAUSE TestValidateToken_NoMatchingProvider2034=== RUN TestValidateToken_KubernetesServiceAccount2035=== PAUSE TestValidateToken_KubernetesServiceAccount2036=== RUN TestNewValidator_KubernetesRequiresCA2037=== PAUSE TestNewValidator_KubernetesRequiresCA2038=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2039=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2040=== RUN TestPins_ReservedForMatchingRule2041=== PAUSE TestPins_ReservedForMatchingRule2042=== RUN TestPins_TopLevelShorthand2043=== PAUSE TestPins_TopLevelShorthand2044=== RUN TestPins_ConfigValidation2045=== PAUSE TestPins_ConfigValidation2046=== RUN TestScopes_LegacyProviderDefaultsToWrite2047=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2048=== RUN TestScopes_Rules2049=== PAUSE TestScopes_Rules2050=== RUN TestScopes_ConfigValidation2051=== PAUSE TestScopes_ConfigValidation2052=== CONT TestAudienceForIssuer2053=== CONT TestPins_ConfigValidation2054=== CONT TestValidateToken_KubernetesServiceAccount2055--- PASS: TestAudienceForIssuer (0.00s)2056=== CONT TestPins_TopLevelShorthand2057=== CONT TestValidateToken_Expired2058=== CONT TestValidateToken_WrongAudience2059--- PASS: TestPins_ConfigValidation (0.00s)2060=== CONT TestPins_ReservedForMatchingRule2061=== CONT TestValidateToken_ValidToken2062=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2063=== CONT TestGlobMatch2064=== RUN TestGlobMatch/foo_foo2065=== PAUSE TestGlobMatch/foo_foo2066=== RUN TestGlobMatch/foo_bar2067=== PAUSE TestGlobMatch/foo_bar2068=== RUN TestGlobMatch/*_2069=== PAUSE TestGlobMatch/*_2070=== RUN TestGlobMatch/*_anything2071=== PAUSE TestGlobMatch/*_anything2072=== RUN TestGlobMatch/foo*_foo2073=== PAUSE TestGlobMatch/foo*_foo2074=== RUN TestGlobMatch/foo*_foobar2075=== PAUSE TestGlobMatch/foo*_foobar2076=== RUN TestGlobMatch/foo*_bar2077=== PAUSE TestGlobMatch/foo*_bar2078=== RUN TestGlobMatch/*bar_bar2079=== PAUSE TestGlobMatch/*bar_bar2080=== CONT TestNewValidator_KubernetesRequiresCA2081=== CONT TestValidateToken_MultipleProviders2082=== CONT TestValidateToken_NoMatchingProvider2083=== CONT TestScopes_Rules2084=== CONT TestValidateToken_BoundSubjectMismatch2085=== CONT TestScopes_ConfigValidation2086=== CONT TestScopes_LegacyProviderDefaultsToWrite2087=== CONT TestValidateToken_BoundClaimsMismatch2088=== RUN TestGlobMatch/*bar_foobar2089=== PAUSE TestGlobMatch/*bar_foobar2090=== RUN TestGlobMatch/*bar_foo2091=== PAUSE TestGlobMatch/*bar_foo2092=== RUN TestGlobMatch/foo*bar_foobar2093=== PAUSE TestGlobMatch/foo*bar_foobar2094=== RUN TestGlobMatch/foo*bar_foo123bar2095=== PAUSE TestGlobMatch/foo*bar_foo123bar2096=== RUN TestGlobMatch/foo*bar_foobarbaz2097=== PAUSE TestGlobMatch/foo*bar_foobarbaz2098=== RUN TestGlobMatch/*/*_foo/bar2099=== PAUSE TestGlobMatch/*/*_foo/bar2100=== RUN TestGlobMatch/*/*_foo2101=== PAUSE TestGlobMatch/*/*_foo2102=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2103=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2104=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02105=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02106=== RUN TestGlobMatch/refs/*/main_refs/heads/main2107=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2108=== RUN TestGlobMatch/fo?_foo2109=== PAUSE TestGlobMatch/fo?_foo2110=== RUN TestGlobMatch/fo?_fo2111=== PAUSE TestGlobMatch/fo?_fo2112=== RUN TestGlobMatch/fo?_fooo2113=== PAUSE TestGlobMatch/fo?_fooo2114=== RUN TestGlobMatch/?oo_foo2115=== PAUSE TestGlobMatch/?oo_foo2116=== RUN TestGlobMatch/?oo_boo2117=== PAUSE TestGlobMatch/?oo_boo2118=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2119=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2120=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2121=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2122=== CONT TestGlobMatch/foo_foo2123=== CONT TestGlobMatch/foo*bar_foobarbaz2124=== CONT TestGlobMatch/foo*bar_foo123bar2125=== CONT TestGlobMatch/foo*bar_foobar2126=== CONT TestGlobMatch/*bar_foo2127=== CONT TestGlobMatch/*bar_foobar2128=== CONT TestGlobMatch/*bar_bar2129=== CONT TestGlobMatch/foo*_bar2130=== CONT TestGlobMatch/foo*_foobar2131=== CONT TestGlobMatch/foo*_foo2132=== CONT TestGlobMatch/*_anything2133=== CONT TestGlobMatch/*_2134=== CONT TestGlobMatch/foo_bar2135=== CONT TestGlobMatch/fo?_fo2136=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2137=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2138=== CONT TestGlobMatch/?oo_boo2139=== CONT TestGlobMatch/*/*_foo/bar2140=== CONT TestGlobMatch/?oo_foo2141=== CONT TestGlobMatch/fo?_fooo2142=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02143=== CONT TestGlobMatch/fo?_foo2144=== CONT TestGlobMatch/refs/*/main_refs/heads/main2145=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2146=== CONT TestGlobMatch/*/*_foo2147--- PASS: TestGlobMatch (0.00s)2148 --- PASS: TestGlobMatch/foo_foo (0.00s)2149 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2150 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2151 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2152 --- PASS: TestGlobMatch/*bar_foo (0.00s)2153 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2154 --- PASS: TestGlobMatch/*bar_bar (0.00s)2155 --- PASS: TestGlobMatch/foo*_bar (0.00s)2156 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2157 --- PASS: TestGlobMatch/foo*_foo (0.00s)2158 --- PASS: TestGlobMatch/*_anything (0.00s)2159 --- PASS: TestGlobMatch/*_ (0.00s)2160 --- PASS: TestGlobMatch/foo_bar (0.00s)2161 --- PASS: TestGlobMatch/fo?_fo (0.00s)2162 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2163 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2164 --- PASS: TestGlobMatch/?oo_boo (0.00s)2165 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2166 --- PASS: TestGlobMatch/?oo_foo (0.00s)2167 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2168 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2169 --- PASS: TestGlobMatch/fo?_foo (0.00s)2170 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2171 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2172 --- PASS: TestGlobMatch/*/*_foo (0.00s)2173--- PASS: TestScopes_ConfigValidation (0.00s)21742026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42115/oidc2175--- PASS: TestPins_TopLevelShorthand (0.02s)21762026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37777/oidc2177--- PASS: TestValidateToken_Expired (0.03s)21782026/10/06 10:43:02 http: TLS handshake error from 127.0.0.1:55812: remote error: tls: bad certificate2179--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)21802026/10/06 10:43:02 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232181--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)21822026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38673/oidc21832026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38409/oidc2184--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)21852026/10/06 10:43:02 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:427872186--- PASS: TestValidateToken_WrongAudience (0.05s)2187--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)21882026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33235/oidc2189--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.05s)21902026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41069/oidc2191--- PASS: TestPins_ReservedForMatchingRule (0.07s)21922026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37833/oidc2193--- PASS: TestValidateToken_ValidToken (0.07s)21942026/10/06 10:43:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43627/oidc21952026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37469/oidc21962026/10/06 10:43:02 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:36257/oidc2197--- PASS: TestValidateToken_MultipleProviders (0.09s)2198--- PASS: TestScopes_Rules (0.10s)21992026/10/06 10:43:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36451/oidc22002026/10/06 10:43:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34679/oidc2201--- PASS: TestValidateToken_NoMatchingProvider (0.13s)2202--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)2203PASS2204Running hook tests...2205=== RUN TestSendPathsEmpty2206=== PAUSE TestSendPathsEmpty2207=== RUN TestQueueEnqueueAndFetch2208=== PAUSE TestQueueEnqueueAndFetch2209=== RUN TestQueueDeduplication2210=== PAUSE TestQueueDeduplication2211=== RUN TestQueueRemove2212=== PAUSE TestQueueRemove2213=== RUN TestQueueFetchBatchLimit2214=== PAUSE TestQueueFetchBatchLimit2215=== RUN TestQueueRetryMovesToBack2216=== PAUSE TestQueueRetryMovesToBack2217=== RUN TestQueueFetchRemoveLifecycle2218=== PAUSE TestQueueFetchRemoveLifecycle2219=== RUN TestQueueConcurrentWriters2220=== PAUSE TestQueueConcurrentWriters2221=== RUN TestQueueRemoveLargeClosure2222=== PAUSE TestQueueRemoveLargeClosure2223=== RUN TestServerClientIntegration2224=== PAUSE TestServerClientIntegration2225=== RUN TestServerQueueError2226=== PAUSE TestServerQueueError2227=== RUN TestGetListenerSocketActivation2228 server_test.go:210: === RUN TestGetListenerSocketActivation2229 --- PASS: TestGetListenerSocketActivation (0.00s)2230 PASS2231 2232--- PASS: TestGetListenerSocketActivation (0.01s)2233=== RUN TestDrainIsolatesPoisonPath2234=== PAUSE TestDrainIsolatesPoisonPath2235=== RUN TestRunNotBlockedByPoisonHead2236=== PAUSE TestRunNotBlockedByPoisonHead2237=== RUN TestDrainGivesUpWhenServerDown2238=== PAUSE TestDrainGivesUpWhenServerDown2239=== RUN TestFailedPathPrunedByLaterClosure2240=== PAUSE TestFailedPathPrunedByLaterClosure2241=== RUN TestWorkerUploadsAndRemoves2242=== PAUSE TestWorkerUploadsAndRemoves2243=== RUN TestWorkerSkipsGCdPaths2244=== PAUSE TestWorkerSkipsGCdPaths2245=== RUN TestWorkerPrunesClosureDeps2246=== PAUSE TestWorkerPrunesClosureDeps2247=== RUN TestDrainTimeout2248=== PAUSE TestDrainTimeout2249=== CONT TestSendPathsEmpty2250=== CONT TestDrainTimeout2251--- PASS: TestSendPathsEmpty (0.00s)2252=== CONT TestServerQueueError2253=== CONT TestQueueFetchBatchLimit2254=== CONT TestQueueRemove2255=== CONT TestQueueDeduplication2256=== CONT TestQueueEnqueueAndFetch2257=== CONT TestWorkerSkipsGCdPaths2258=== CONT TestWorkerPrunesClosureDeps2259=== CONT TestWorkerUploadsAndRemoves22602026/10/06 10:43:02 ERROR Failed to queue paths error="permission denied" count=12261=== CONT TestRunNotBlockedByPoisonHead2262=== CONT TestDrainGivesUpWhenServerDown2263=== CONT TestQueueRemoveLargeClosure2264--- PASS: TestServerQueueError (0.00s)2265=== CONT TestQueueConcurrentWriters2266=== CONT TestServerClientIntegration2267=== CONT TestQueueFetchRemoveLifecycle2268=== CONT TestDrainIsolatesPoisonPath2269=== CONT TestFailedPathPrunedByLaterClosure2270=== CONT TestQueueRetryMovesToBack2271--- PASS: TestServerClientIntegration (0.00s)22722026/10/06 10:43:02 INFO Uploading batch count=422732026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=422742026/10/06 10:43:02 INFO Upload queue status pending=222752026/10/06 10:43:02 INFO Uploading batch count=122762026/10/06 10:43:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1297548241/002/bbb22772026/10/06 10:43:02 INFO Uploading batch count=222782026/10/06 10:43:02 INFO Uploading batch count=222792026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=222802026/10/06 10:43:02 INFO Uploading batch count=12281--- PASS: TestQueueEnqueueAndFetch (0.02s)22822026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=122832026/10/06 10:43:02 INFO Upload queue status pending=322842026/10/06 10:43:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown93340898/002/a22852026/10/06 10:43:02 INFO Upload queue status pending=22286--- PASS: TestQueueDeduplication (0.02s)22872026/10/06 10:43:02 INFO Uploading batch count=122882026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=122892026/10/06 10:43:02 INFO Uploading batch count=22290--- PASS: TestQueueFetchBatchLimit (0.02s)22912026/10/06 10:43:02 INFO Upload queue status pending=222922026/10/06 10:43:02 INFO Uploading batch count=122932026/10/06 10:43:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3220842063/002/nonexistent2294--- PASS: TestQueueRetryMovesToBack (0.02s)2295--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22962026/10/06 10:43:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown93340898/002/b22972026/10/06 10:43:02 INFO Uploading batch count=122982026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=122992026/10/06 10:43:02 INFO Uploading batch count=12300--- PASS: TestQueueRemove (0.03s)23012026/10/06 10:43:02 INFO Uploading batch count=123022026/10/06 10:43:02 INFO Uploading batch count=223032026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=223042026/10/06 10:43:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown93340898/002/c23052026/10/06 10:43:02 INFO Uploading batch count=123062026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=123072026/10/06 10:43:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown93340898/002/d23082026/10/06 10:43:02 INFO Uploading batch count=123092026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=123102026/10/06 10:43:02 INFO Uploading batch count=223112026/10/06 10:43:02 ERROR Upload failed error="upload failed" count=223122026/10/06 10:43:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown93340898/002/e2313--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)23142026/10/06 10:43:02 ERROR Drain finished with paths left in queue remaining=123152026/10/06 10:43:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown93340898/002/f23162026/10/06 10:43:02 ERROR Drain finished with paths left in queue remaining=102317--- PASS: TestDrainIsolatesPoisonPath (0.03s)2318--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2319--- PASS: TestWorkerPrunesClosureDeps (0.04s)2320--- PASS: TestWorkerUploadsAndRemoves (0.04s)2321--- PASS: TestWorkerSkipsGCdPaths (0.04s)2322--- PASS: TestQueueRemoveLargeClosure (0.08s)23232026/10/06 10:43:02 ERROR Upload failed error="context deadline exceeded" count=223242026/10/06 10:43:02 ERROR Drain finished with paths left in queue remaining=42325--- PASS: TestDrainTimeout (0.23s)2326--- PASS: TestQueueConcurrentWriters (0.30s)23272026/10/06 10:43:03 INFO Uploading batch count=123282026/10/06 10:43:03 INFO Uploading batch count=123292026/10/06 10:43:03 INFO Uploading batch count=123302026/10/06 10:43:03 ERROR Upload failed error="upload failed" count=123312026/10/06 10:43:03 INFO Uploading batch count=123322026/10/06 10:43:03 ERROR Upload failed error="upload failed" count=123332026/10/06 10:43:03 INFO Uploading batch count=123342026/10/06 10:43:03 ERROR Upload failed error="upload failed" count=123352026/10/06 10:43:03 INFO Uploading batch count=123362026/10/06 10:43:03 ERROR Upload failed error="upload failed" count=123372026/10/06 10:43:03 ERROR Drain finished with paths left in queue remaining=12338--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2339PASS2340Running signing tests...2341=== RUN TestExternalSigner2342=== PAUSE TestExternalSigner2343=== RUN TestExternalSignerWrongPublicKey2344=== PAUSE TestExternalSignerWrongPublicKey2345=== RUN TestExternalSignerErrors2346=== PAUSE TestExternalSignerErrors2347=== RUN TestExternalSignerRestartsAfterCrash2348=== PAUSE TestExternalSignerRestartsAfterCrash2349=== RUN TestExternalSignerProgramErrorKeepsProcess2350=== PAUSE TestExternalSignerProgramErrorKeepsProcess2351=== RUN TestExternalSignerClose2352=== PAUSE TestExternalSignerClose2353=== RUN TestExternalSignerRejectsInvalidPublicKey2354=== PAUSE TestExternalSignerRejectsInvalidPublicKey2355=== RUN TestExternalSignerCancellation2356=== PAUSE TestExternalSignerCancellation2357=== RUN TestGenerateFingerprint2358=== PAUSE TestGenerateFingerprint2359=== RUN TestParseSigningKey2360=== PAUSE TestParseSigningKey2361=== RUN TestSign2362=== PAUSE TestSign2363=== RUN TestSignBatch2364=== PAUSE TestSignBatch2365=== RUN TestNilKeyPublicKey2366=== PAUSE TestNilKeyPublicKey2367=== RUN TestSignErrors2368=== PAUSE TestSignErrors2369=== CONT TestExternalSigner2370=== CONT TestExternalSignerCancellation2371=== CONT TestSign2372=== CONT TestSignBatch2373=== CONT TestExternalSignerProgramErrorKeepsProcess2374=== CONT TestExternalSignerRejectsInvalidPublicKey2375=== CONT TestExternalSignerClose2376=== CONT TestExternalSignerErrors2377=== RUN TestExternalSignerErrors/null2378=== PAUSE TestExternalSignerErrors/null2379=== CONT TestExternalSignerRestartsAfterCrash2380=== CONT TestSignErrors2381=== CONT TestParseSigningKey2382=== CONT TestNilKeyPublicKey2383=== CONT TestExternalSignerWrongPublicKey2384=== CONT TestGenerateFingerprint2385=== RUN TestExternalSignerRejectsInvalidPublicKey/#002386=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002387=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2388=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2389=== RUN TestExternalSignerErrors/unrequested_key2390=== PAUSE TestExternalSignerErrors/unrequested_key2391=== RUN TestParseSigningKey/valid_32-byte_key2392=== PAUSE TestParseSigningKey/valid_32-byte_key2393=== RUN TestSignErrors/nil_key2394=== RUN TestGenerateFingerprint/basic_with_references2395--- PASS: TestSign (0.00s)2396--- PASS: TestNilKeyPublicKey (0.00s)2397--- PASS: TestSignBatch (0.00s)2398=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2399=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2400=== RUN TestExternalSignerErrors/invalid_signature_base642401=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2402=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2403=== PAUSE TestExternalSignerErrors/invalid_signature_base642404=== PAUSE TestSignErrors/nil_key2405=== RUN TestSignErrors/nil_narinfo2406=== PAUSE TestSignErrors/nil_narinfo2407=== RUN TestSignErrors/invalid_narinfo2408=== PAUSE TestSignErrors/invalid_narinfo2409=== RUN TestSignErrors/canceled2410=== PAUSE TestSignErrors/canceled2411=== CONT TestSignErrors/nil_key2412=== PAUSE TestGenerateFingerprint/basic_with_references2413=== CONT TestSignErrors/canceled2414=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2415=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2416=== RUN TestParseSigningKey/no_colon2417=== PAUSE TestParseSigningKey/no_colon2418=== RUN TestParseSigningKey/empty_name2419=== PAUSE TestParseSigningKey/empty_name2420=== RUN TestParseSigningKey/invalid_base642421=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2422=== RUN TestExternalSignerErrors/exit_at_startup2423=== PAUSE TestExternalSignerErrors/exit_at_startup2424=== RUN TestExternalSignerErrors/exit_on_request2425=== PAUSE TestExternalSignerErrors/exit_on_request2426=== RUN TestExternalSignerErrors/null_signatures2427=== PAUSE TestExternalSignerErrors/null_signatures2428=== RUN TestGenerateFingerprint/no_references2429=== CONT TestSignErrors/nil_narinfo2430=== CONT TestSignErrors/invalid_narinfo2431--- PASS: TestSignErrors (0.00s)2432 --- PASS: TestSignErrors/nil_key (0.00s)2433 --- PASS: TestSignErrors/canceled (0.00s)2434 --- PASS: TestSignErrors/nil_narinfo (0.00s)2435 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2436=== PAUSE TestParseSigningKey/invalid_base642437=== RUN TestParseSigningKey/wrong_length2438=== PAUSE TestParseSigningKey/wrong_length2439=== CONT TestParseSigningKey/valid_32-byte_key2440=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2441=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2442=== CONT TestExternalSignerRejectsInvalidPublicKey/#002443=== CONT TestParseSigningKey/invalid_base642444=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2445=== RUN TestExternalSignerErrors/too_few_signatures2446=== PAUSE TestExternalSignerErrors/too_few_signatures2447=== RUN TestExternalSignerErrors/wrong_signature_name2448=== PAUSE TestExternalSignerErrors/wrong_signature_name2449=== RUN TestExternalSignerErrors/invalid_JSON2450=== PAUSE TestExternalSignerErrors/invalid_JSON2451=== RUN TestExternalSignerErrors/missing_signatures2452=== PAUSE TestGenerateFingerprint/no_references2453=== CONT TestParseSigningKey/wrong_length2454=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2455=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2456=== CONT TestParseSigningKey/no_colon2457=== CONT TestParseSigningKey/empty_name2458--- PASS: TestExternalSignerClose (0.00s)2459=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2460=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2461=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2462=== PAUSE TestExternalSignerErrors/missing_signatures2463=== RUN TestExternalSignerErrors/missing_signature_name2464=== PAUSE TestExternalSignerErrors/missing_signature_name2465=== RUN TestExternalSignerErrors/wrong_signature_length2466=== PAUSE TestExternalSignerErrors/wrong_signature_length2467=== RUN TestExternalSignerErrors/program_error2468=== PAUSE TestExternalSignerErrors/program_error2469=== RUN TestExternalSignerErrors/wrong_shape2470=== PAUSE TestExternalSignerErrors/wrong_shape2471=== RUN TestExternalSignerErrors/wrong_id2472=== PAUSE TestExternalSignerErrors/wrong_id2473=== RUN TestExternalSignerErrors/wrong_signatures_shape2474=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2475=== CONT TestExternalSignerErrors/null2476=== CONT TestExternalSignerErrors/null_signatures2477=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2478=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2479=== CONT TestExternalSignerErrors/missing_signature_name2480--- PASS: TestExternalSignerWrongPublicKey (0.00s)2481=== CONT TestExternalSignerErrors/wrong_signatures_shape2482=== CONT TestExternalSignerErrors/wrong_id2483=== CONT TestExternalSignerErrors/wrong_signature_length2484=== CONT TestExternalSignerErrors/program_error2485=== CONT TestExternalSignerErrors/wrong_shape2486=== CONT TestExternalSignerErrors/invalid_JSON2487=== CONT TestExternalSignerErrors/exit_at_startup2488=== CONT TestExternalSignerErrors/missing_signatures2489=== CONT TestExternalSignerErrors/exit_on_request2490=== CONT TestExternalSignerErrors/unrequested_key2491=== CONT TestExternalSignerErrors/invalid_signature_base642492=== CONT TestExternalSignerErrors/wrong_signature_name2493=== CONT TestExternalSignerErrors/too_few_signatures2494=== RUN TestGenerateFingerprint/invalid_nar_hash_length2495--- PASS: TestParseSigningKey (0.00s)2496 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2497 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2498 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2499 --- PASS: TestParseSigningKey/wrong_length (0.00s)2500 --- PASS: TestParseSigningKey/no_colon (0.00s)2501 --- PASS: TestParseSigningKey/empty_name (0.00s)2502--- PASS: TestExternalSigner (0.01s)2503--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2504--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2505 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2506 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2507 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2508 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2509 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2510=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2511=== RUN TestGenerateFingerprint/invalid_store_path_prefix2512=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2513=== RUN TestGenerateFingerprint/invalid_reference_prefix2514=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2515=== CONT TestGenerateFingerprint/invalid_store_path_prefix2516=== CONT TestGenerateFingerprint/basic_with_references2517=== CONT TestGenerateFingerprint/invalid_nar_hash_length2518=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2519=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2520=== CONT TestGenerateFingerprint/no_references2521=== CONT TestGenerateFingerprint/invalid_reference_prefix2522--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2523--- PASS: TestGenerateFingerprint (0.01s)2524 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2525 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2526 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2527 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2528 --- PASS: TestGenerateFingerprint/no_references (0.00s)2529 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2530 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2531--- PASS: TestExternalSignerErrors (0.00s)2532 --- PASS: TestExternalSignerErrors/null (0.00s)2533 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2534 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2535 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2536 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2537 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2538 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2539 --- PASS: TestExternalSignerErrors/program_error (0.01s)2540 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2541 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2542 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2543 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2544 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2545 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2546 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2547 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2548--- PASS: TestExternalSignerCancellation (0.02s)2549PASS2550Running OpenBao signer tests...2551=== RUN TestSign2552=== PAUSE TestSign2553=== RUN TestSignErrors2554=== PAUSE TestSignErrors2555=== RUN TestServe2556=== PAUSE TestServe2557=== RUN TestServeRejectsGarbage2558=== PAUSE TestServeRejectsGarbage2559=== CONT TestSign2560=== CONT TestSignErrors2561=== CONT TestServeRejectsGarbage2562=== RUN TestSignErrors/invalid_json2563--- PASS: TestServeRejectsGarbage (0.00s)2564=== CONT TestServe2565=== PAUSE TestSignErrors/invalid_json2566=== RUN TestSignErrors/no_prefix2567=== PAUSE TestSignErrors/no_prefix2568=== RUN TestSignErrors/invalid_base642569=== PAUSE TestSignErrors/invalid_base642570=== RUN TestSignErrors/http_error2571=== PAUSE TestSignErrors/http_error2572=== CONT TestSignErrors/invalid_json2573=== CONT TestSignErrors/invalid_base642574=== CONT TestSignErrors/http_error2575--- PASS: TestServe (0.00s)2576=== CONT TestSignErrors/no_prefix2577--- PASS: TestSign (0.00s)2578--- PASS: TestSignErrors (0.00s)2579 --- PASS: TestSignErrors/invalid_json (0.00s)2580 --- PASS: TestSignErrors/invalid_base64 (0.00s)2581 --- PASS: TestSignErrors/http_error (0.00s)2582 --- PASS: TestSignErrors/no_prefix (0.00s)2583PASS