niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #381
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== CONT TestScriptTokenEmptyCommand103=== RUN TestEncodeNixBase32/test_string_hash104--- PASS: TestScriptTokenEmptyCommand (0.00s)105=== PAUSE TestEncodeNixBase32/test_string_hash106=== CONT TestScriptTokenBadJSON107=== CONT TestScriptTokenEmptyToken108=== CONT TestScriptTokenCachesUntilRefresh109=== CONT TestScriptTokenNoExpiryRerunsEveryCall110=== CONT TestFileTokenEmpty111=== CONT TestFileTokenMissing112=== CONT TestFileTokenReadsAndCaches113=== CONT TestStaticToken114=== CONT TestUploadMultipart_PartsInParallel115=== CONT TestDumpPathWriterError116=== CONT TestDumpPathSingleFile117=== CONT TestDumpPathMatchesNix118=== CONT TestUploadMultipart_SupersededByPeer119=== CONT TestPathInfoCACompatibility120=== RUN TestUploadMultipart_SupersededByPeer/exists121=== CONT TestPartSizeForNAR122=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun123=== CONT TestFilterOversizedClosures124=== CONT TestCaseHackSuffix125=== CONT TestParsePathInfoJSONMultiplePaths126=== CONT TestSetClientTLSErrors127=== CONT TestScriptTokenScriptFails128=== CONT TestResolveStorePath129=== RUN TestEncodeNixBase32/empty_input130--- PASS: TestStaticToken (0.00s)131=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess132=== CONT TestRateLimiterFeedback133=== RUN TestRateLimiterFeedback/429_enables_limiter134--- PASS: TestFileTokenMissing (0.00s)135=== RUN TestPathInfoCACompatibility/null_ca_field136=== PAUSE TestPathInfoCACompatibility/null_ca_field137--- PASS: TestScriptTokenBadJSON (0.01s)138--- PASS: TestScriptTokenEmptyToken (0.01s)139=== RUN TestPathInfoCACompatibility/old_string_format_-_text140=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text141=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive142--- PASS: TestFileTokenReadsAndCaches (0.00s)143=== CONT TestStreamPushGivesUpOnDeadServer144=== CONT TestSetClientTLSDoesNotMutateDefaultTransport145=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive146=== RUN TestPartSizeForNAR/zero_stays_at_minimum147=== CONT TestStreamPushReportsSignatures148=== RUN TestPathInfoCACompatibility/new_structured_format_-_text149=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text150=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method151=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method152=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum153=== CONT TestStreamPushRequestLine1542026/10/06 21:12:52 WARN Rate limiter enabled after throttle name=server-test rate=5155--- PASS: TestFileTokenEmpty (0.02s)156--- PASS: TestDoServerRequestAttachesToken (0.02s)1572026/10/06 21:12:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41211158=== CONT TestSetClientTLS1592026/10/06 21:12:52 ERROR Upload failed error="connection refused" count=201602026/10/06 21:12:52 ERROR Server seems unavailable, giving up on batch untried=171612026/10/06 21:12:52 WARN Rate limiter enabled after throttle name=server-test rate=5162=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica163=== CONT TestStreamPushReportsEveryPath1642026/10/06 21:12:52 ERROR Upload failed error=boom count=11652026/10/06 21:12:52 WARN Rate limiter backed off name=server-test rate=5166=== CONT TestStreamPushIsolatesFailures167=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths168=== CONT TestClientSignaturesByStorePath169=== PAUSE TestEncodeNixBase32/empty_input170=== PAUSE TestUploadMultipart_SupersededByPeer/exists171=== PAUSE TestRateLimiterFeedback/429_enables_limiter1722026/10/06 21:12:52 ERROR Upload failed error="bad path" count=3173=== RUN TestUploadMultipart_SupersededByPeer/missing174=== PAUSE TestUploadMultipart_SupersededByPeer/missing175=== RUN TestFilterOversizedClosures/no_limit_keeps_everything176=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything177=== CONT TestShellSplit178=== RUN TestPartSizeForNAR/small_stays_at_minimum1792026/10/06 21:12:52 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41211180=== PAUSE TestPartSizeForNAR/small_stays_at_minimum181=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum182=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum183--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)184--- PASS: TestResolveStorePath (0.00s)1852026/10/06 21:12:52 ERROR Upload failed error=boom count=1186--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)187--- PASS: TestStreamPushReportsSignatures (0.00s)188=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped189=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1902026/10/06 21:12:52 INFO Garbage collection started191=== CONT TestStreamPushBatchesUnderLoad192=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths193=== CONT TestShellSplitErrors194=== CONT TestPathInfoHashCompatibility195=== CONT TestRegisterUploadedObjectReusesConnections196=== RUN TestRateLimiterFeedback/503_enables_limiter197=== CONT TestEncodeNixBase32WithRealHash1982026/10/06 21:12:52 INFO Garbage collection started199=== CONT TestConvertHashToNix32200=== RUN TestConvertHashToNix32/SRI_format_to_Nix32201=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32202=== RUN TestConvertHashToNix32/already_Nix32_format203=== PAUSE TestConvertHashToNix32/already_Nix32_format204=== RUN TestConvertHashToNix32/invalid_format205=== PAUSE TestRateLimiterFeedback/503_enables_limiter206=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter207=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter208=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter209=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter210=== CONT TestPathInfoCACompatibility/null_ca_field211=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method212=== CONT TestPathInfoCACompatibility/old_string_format_-_text213=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive214=== RUN TestSetClientTLSErrors/missing_cert_file215=== PAUSE TestSetClientTLSErrors/missing_cert_file216=== RUN TestSetClientTLSErrors/missing_key_file217=== PAUSE TestSetClientTLSErrors/missing_key_file218=== RUN TestSetClientTLSErrors/missing_ca_file219=== PAUSE TestSetClientTLSErrors/missing_ca_file220=== RUN TestSetClientTLSErrors/invalid_ca_file2212026/10/06 21:12:52 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=0222=== CONT TestPathInfoCACompatibility/new_structured_format_-_text223=== CONT TestEncodeNixBase32/empty_input224=== CONT TestUploadMultipart_SupersededByPeer/exists225=== CONT TestUploadMultipart_SupersededByPeer/missing226=== CONT TestRateLimiterFeedback/429_enables_limiter227=== CONT TestEncodeNixBase32/test_string_hash228=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter229=== RUN TestSetClientTLS/rejects_connection_without_client_cert230=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert231=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA232=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA233=== RUN TestSetClientTLS/preserves_debug_logging_transport234=== PAUSE TestSetClientTLS/preserves_debug_logging_transport235=== PAUSE TestSetClientTLSErrors/invalid_ca_file236=== CONT TestRateLimiterFeedback/503_enables_limiter237=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter238=== CONT TestParsePathInfoJSON2392026/10/06 21:12:52 WARN Garbage collection finished on another replica. Its statistics are not available here240=== RUN TestParsePathInfoJSON/Nix_format241=== PAUSE TestParsePathInfoJSON/Nix_format242=== RUN TestParsePathInfoJSON/Lix_format243=== PAUSE TestParsePathInfoJSON/Lix_format244=== CONT TestSetClientTLS/rejects_connection_without_client_cert245--- PASS: TestClientSignaturesByStorePath (0.00s)246--- PASS: TestStreamPushReportsEveryPath (0.00s)247--- PASS: TestShellSplit (0.00s)248--- PASS: TestStreamPushIsolatesFailures (0.00s)249=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped250=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths251=== RUN TestParsePathInfoJSON/empty_input252=== PAUSE TestParsePathInfoJSON/empty_input253=== RUN TestParsePathInfoJSON/whitespace_only254=== PAUSE TestParsePathInfoJSON/whitespace_only255=== RUN TestParsePathInfoJSON/invalid_JSON2562026/10/06 21:12:52 WARN Rate limiter enabled after throttle name=server-test rate=5257=== PAUSE TestParsePathInfoJSON/invalid_JSON2582026/10/06 21:12:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33953259=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)260=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)261=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon262=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon263=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2642026/10/06 21:12:52 WARN Rate limiter backed off name=server-test rate=5265=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI266=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512267=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512268=== CONT TestSetClientTLSErrors/missing_cert_file269=== CONT TestSetClientTLS/preserves_debug_logging_transport270=== CONT TestParsePathInfoJSON/Nix_format271=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths272=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)273=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts274=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts2752026/10/06 21:12:52 WARN Rate limiter enabled after throttle name=server-test rate=5276=== RUN TestPartSizeForNAR/1_TiB2772026/10/06 21:12:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:45761278=== PAUSE TestPartSizeForNAR/1_TiB279=== CONT TestSetClientTLSErrors/missing_ca_file280=== RUN TestFilterOversizedClosures/all_closures_skipped281=== PAUSE TestFilterOversizedClosures/all_closures_skipped282=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2832026/10/06 21:12:52 WARN Rate limiter backed off name=server-test rate=5284=== CONT TestGetStorePathHash285=== CONT TestParsePathInfoJSON/Lix_format286=== RUN TestGetStorePathHash/valid_store_path287=== CONT TestFilterOversizedClosures/all_closures_skipped2882026/10/06 21:12:52 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50289=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2902026/10/06 21:12:52 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=2000291=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI292=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512293=== CONT TestSetClientTLSErrors/missing_key_file294=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon295=== PAUSE TestGetStorePathHash/valid_store_path296=== RUN TestGetStorePathHash/basename_without_hyphen_should_error297=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error298=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error299=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error300=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error301=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error302=== CONT TestGetStorePathHash/valid_store_path303=== RUN TestPartSizeForNAR/5_TiB_S3_max_object304=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object305=== RUN TestPartSizeForNAR/capped_at_5_GiB306=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error307=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error308=== CONT TestParsePathInfoJSON/empty_input309=== PAUSE TestConvertHashToNix32/invalid_format310=== CONT TestConvertHashToNix32/SRI_format_to_Nix32311=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA312=== CONT TestConvertHashToNix32/invalid_format313=== CONT TestConvertHashToNix32/already_Nix32_format314=== CONT TestFilterOversizedClosures/no_limit_keeps_everything315=== CONT TestParsePathInfoJSON/invalid_JSON316=== CONT TestSetClientTLSErrors/invalid_ca_file317=== CONT TestParsePathInfoJSON/whitespace_only318=== PAUSE TestPartSizeForNAR/capped_at_5_GiB319=== CONT TestPartSizeForNAR/zero_stays_at_minimum320=== CONT TestGetStorePathHash/basename_without_hyphen_should_error321--- PASS: TestShellSplitErrors (0.00s)322--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)323--- PASS: TestEncodeNixBase32WithRealHash (0.00s)324--- PASS: TestScriptTokenScriptFails (0.00s)325=== CONT TestPartSizeForNAR/1_TiB326=== CONT TestPartSizeForNAR/capped_at_5_GiB327=== CONT TestPartSizeForNAR/5_TiB_S3_max_object328=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts329=== CONT TestPartSizeForNAR/small_stays_at_minimum330=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum331--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)332--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)333--- PASS: TestPathInfoCACompatibility (0.02s)334 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)335 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)336 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)337 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)338 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)339--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)340--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)341--- PASS: TestEncodeNixBase32 (0.02s)342 --- PASS: TestEncodeNixBase32/empty_input (0.00s)343 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)344--- PASS: TestPathInfoHashCompatibility (0.00s)345 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)348 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)349--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)350 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)351 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)352--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)353 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)354 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)355--- PASS: TestGetStorePathHash (0.00s)356 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)357 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)358 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)359 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)360--- PASS: TestPartSizeForNAR (0.01s)361 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)365 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)366 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)368--- PASS: TestRateLimiterFeedback (0.02s)369 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)370 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)371 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)373--- PASS: TestConvertHashToNix32 (0.01s)374 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)375 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)376 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)377--- PASS: TestFilterOversizedClosures (0.01s)378 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)379 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)380 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)381--- PASS: TestParsePathInfoJSON (0.00s)382 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)383 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)384 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)385 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)386 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)387--- PASS: TestSetClientTLSErrors (0.01s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)391 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3922026/10/06 21:12:52 http: TLS handshake error from 127.0.0.1:46678: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.00s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397--- PASS: TestDumpPathSingleFile (0.05s)398--- PASS: TestStreamPushRequestLine (0.03s)399--- PASS: TestCaseHackSuffix (0.05s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)401--- PASS: TestDumpPathWriterError (0.08s)402--- PASS: TestDumpPathMatchesNix (0.11s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.67s)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/postgres1688502931/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/postgres1688502931/data -l logfile start434435/build/postgres1688502931:5432 - no response4362026-10-06 21:12:55.425 UTC [132] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:12:55.428 UTC [132] LOG: listening on Unix socket "/build/postgres1688502931/.s.PGSQL.5432"4382026-10-06 21:12:55.447 UTC [139] LOG: database system was shut down at 2026-10-06 21:12:54 UTC4392026-10-06 21:12:55.453 UTC [132] LOG: database system is ready to accept connections440/build/postgres1688502931:5432 - accepting connections441{"timestamp":"2026-10-06T21:12:55.835311183Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"da6b4de9-45b9-4507-8d66-a36744b817da","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(387)"}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 21:12:56 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 21:12:56 INFO lead: released remote=192.0.2.1:12344892026/10/06 21:12:56 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:12:57 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.86s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 21:12:57 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 21:12:59.342 UTC [581] FATAL: terminating connection due to administrator command4992026/10/06 21:12:59 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 21:13:00 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 21:13:00 INFO lead: released remote=192.0.2.1:12345022026/10/06 21:13:00 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (3.14s)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 TestPresentRefreshesOnlyStaleClosures593=== PAUSE TestPresentRefreshesOnlyStaleClosures594=== RUN TestPresentNotReportedWhileGCDeletesClosure595=== PAUSE TestPresentNotReportedWhileGCDeletesClosure596=== RUN TestParseSingleRange597=== PAUSE TestParseSingleRange598=== RUN TestProxyHeadersOnlyTrustedOnSocket599=== PAUSE TestProxyHeadersOnlyTrustedOnSocket600=== RUN TestIsValidCachePath601=== PAUSE TestIsValidCachePath602=== RUN TestReadProxyNarinfo603=== PAUSE TestReadProxyNarinfo604=== RUN TestReadProxyNarinfoAlreadyDecompressed605=== PAUSE TestReadProxyNarinfoAlreadyDecompressed606=== RUN TestReadProxyContentNegotiation607=== PAUSE TestReadProxyContentNegotiation608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyOutlastsServerWriteTimeout617=== PAUSE TestReadProxyOutlastsServerWriteTimeout618=== RUN TestReadProxyConditionalGet619=== PAUSE TestReadProxyConditionalGet620=== RUN TestReadProxyRootRedirectsToIndexHTML621=== PAUSE TestReadProxyRootRedirectsToIndexHTML622=== RUN TestReadProxyDisabled623=== PAUSE TestReadProxyDisabled624=== RUN TestReadRedirectNar625=== PAUSE TestReadRedirectNar626=== RUN TestReadRedirectKeepsNarinfoProxied627=== PAUSE TestReadRedirectKeepsNarinfoProxied628=== RUN TestReadProxyRangeRequest629=== PAUSE TestReadProxyRangeRequest630=== RUN TestReadRedirectUsesPublicS3URL631=== PAUSE TestReadRedirectUsesPublicS3URL632=== RUN TestPush_OverlappingRootsStoreOneRowPerKey633=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey634=== RUN TestPush_CompleteCommitsEveryRoot635=== PAUSE TestPush_CompleteCommitsEveryRoot636=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit637=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit638=== RUN TestPush_RejectsBadRequests639=== PAUSE TestPush_RejectsBadRequests640=== RUN TestPush_SignsNarinfosOfItsPendingObjects641=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects642=== RUN TestRedundantMultipartUpload643=== PAUSE TestRedundantMultipartUpload644=== RUN TestCompleteMultipartUpload_ErrorButObjectExists645=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists646=== RUN TestCompletedNarNotReofferedAcrossClosures647=== PAUSE TestCompletedNarNotReofferedAcrossClosures648=== RUN TestPresignedUploadRegisteredBeforeCommit649=== PAUSE TestPresignedUploadRegisteredBeforeCommit650=== RUN TestService_Rustfstest651=== PAUSE TestService_Rustfstest652=== RUN TestParseSize653=== PAUSE TestParseSize654=== RUN TestSkippedUploadsHandler655=== PAUSE TestSkippedUploadsHandler656=== RUN TestSystemdListenerNotActivated657--- PASS: TestSystemdListenerNotActivated (0.00s)658=== RUN TestWatchdogBeatsWhenHealthy659--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)660=== RUN TestWatchdogSkipsWhenUnhealthy6612026/10/06 21:13:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:13:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"671--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)672=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle673=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle674=== RUN TestProxyWriteTimeout675=== PAUSE TestProxyWriteTimeout676=== RUN TestPendingClosureWriteTimeout677=== PAUSE TestPendingClosureWriteTimeout678=== RUN TestIsValidUploadKey679=== PAUSE TestIsValidUploadKey680=== RUN TestUploadHandlersRejectInvalidKeys681=== PAUSE TestUploadHandlersRejectInvalidKeys682=== RUN TestUploadHandlersRejectOversizedBody683=== PAUSE TestUploadHandlersRejectOversizedBody684=== RUN TestService_cleanupPendingClosuresHandler685=== PAUSE TestService_cleanupPendingClosuresHandler686=== RUN TestService_createPendingClosureHandler687=== PAUSE TestService_createPendingClosureHandler688=== RUN TestService_verifyS3Integrity689=== PAUSE TestService_verifyS3Integrity690=== RUN TestCompleteMultipartUnregistered691=== PAUSE TestCompleteMultipartUnregistered692=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT693=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT694=== CONT TestService_AuthMiddleware695=== CONT TestPresignedUploadRegisteredBeforeCommit696=== CONT TestPush_OverlappingRootsStoreOneRowPerKey697=== CONT TestReadProxyHead698=== CONT TestReadRedirectNar699=== CONT TestCompleteMultipartUnregistered700=== CONT TestService_verifyS3Integrity701=== CONT TestService_createPendingClosureHandler702=== CONT TestService_cleanupPendingClosuresHandler703=== CONT TestUploadHandlersRejectOversizedBody704=== CONT TestUploadHandlersRejectInvalidKeys705=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info706=== CONT TestIsValidUploadKey707=== CONT TestPendingClosureWriteTimeout708=== CONT TestProxyWriteTimeout709=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle710=== CONT TestSkippedUploadsHandler711=== CONT TestParseSize712=== CONT TestService_Rustfstest713=== CONT TestReadRedirectUsesPublicS3URL714=== CONT TestReadProxyRangeRequest715=== CONT TestReadRedirectKeepsNarinfoProxied716=== CONT TestReadProxyRootRedirectsToIndexHTML717=== CONT TestReadProxyDisabled718=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT719=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info720=== RUN TestIsValidUploadKey/narinfo721=== PAUSE TestIsValidUploadKey/narinfo722=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal723=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal724=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key725=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key726=== RUN TestPendingClosureWriteTimeout/empty727=== RUN TestProxyWriteTimeout/narinfo728=== PAUSE TestProxyWriteTimeout/narinfo729--- PASS: TestParseSize (0.00s)730=== CONT TestCommitRacingPendingCleanupKeepsObjects731=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key732=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key733=== CONT TestReadProxyInvalidPath734=== RUN TestIsValidUploadKey/nar_zst735=== PAUSE TestPendingClosureWriteTimeout/empty7362026/10/06 21:13:01 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000737=== RUN TestProxyWriteTimeout/1_GiB_nar738=== RUN TestPendingClosureWriteTimeout/400_objects739=== PAUSE TestIsValidUploadKey/nar_zst740=== PAUSE TestProxyWriteTimeout/1_GiB_nar741=== PAUSE TestPendingClosureWriteTimeout/400_objects742=== RUN TestPendingClosureWriteTimeout/670k_objects743=== PAUSE TestPendingClosureWriteTimeout/670k_objects744=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline745=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline746=== RUN TestIsValidUploadKey/nar_xz747=== PAUSE TestIsValidUploadKey/nar_xz748=== RUN TestIsValidUploadKey/nar_plain749=== PAUSE TestIsValidUploadKey/nar_plain750=== RUN TestIsValidUploadKey/listing751=== RUN TestProxyWriteTimeout/10_GiB_nar752=== PAUSE TestProxyWriteTimeout/10_GiB_nar753=== CONT TestReadProxy404754=== PAUSE TestIsValidUploadKey/listing755=== RUN TestProxyWriteTimeout/unknown_size756=== PAUSE TestProxyWriteTimeout/unknown_size757=== RUN TestIsValidUploadKey/build_log758=== PAUSE TestIsValidUploadKey/build_log759=== CONT TestReadProxyNarStreaming760=== RUN TestIsValidUploadKey/build_log_home-manager_file761=== PAUSE TestIsValidUploadKey/build_log_home-manager_file762=== RUN TestIsValidUploadKey/build_log_plus_in_name763=== PAUSE TestIsValidUploadKey/build_log_plus_in_name764=== RUN TestIsValidUploadKey/build_log_question_mark765=== PAUSE TestIsValidUploadKey/build_log_question_mark766=== RUN TestIsValidUploadKey/build_log_equals767=== PAUSE TestIsValidUploadKey/build_log_equals768=== RUN TestIsValidUploadKey/realisation769=== PAUSE TestIsValidUploadKey/realisation770=== RUN TestIsValidUploadKey/realisation_plus_in_output771=== PAUSE TestIsValidUploadKey/realisation_plus_in_output772=== RUN TestIsValidUploadKey/nix-cache-info773=== PAUSE TestIsValidUploadKey/nix-cache-info774=== RUN TestIsValidUploadKey/index.html775=== PAUSE TestIsValidUploadKey/index.html776=== RUN TestIsValidUploadKey/narinfo_key,_nar_type777=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type778=== RUN TestIsValidUploadKey/nar_key,_narinfo_type779=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type780=== RUN TestIsValidUploadKey/listing_key,_narinfo_type781=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type782=== RUN TestIsValidUploadKey/traversal783=== PAUSE TestIsValidUploadKey/traversal784=== RUN TestIsValidUploadKey/traversal_nar785=== PAUSE TestIsValidUploadKey/traversal_nar786=== RUN TestIsValidUploadKey/absolute787=== PAUSE TestIsValidUploadKey/absolute788=== RUN TestIsValidUploadKey/empty_key789=== PAUSE TestIsValidUploadKey/empty_key790=== RUN TestIsValidUploadKey/unknown_type791=== PAUSE TestIsValidUploadKey/unknown_type792=== CONT TestReadProxyContentNegotiation793--- PASS: TestSkippedUploadsHandler (0.08s)794=== CONT TestReadProxyNarinfoAlreadyDecompressed795=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure796=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure797=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart798=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart799=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts800=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts801=== CONT TestReadProxyNarinfo802--- PASS: TestReadProxyHead (0.36s)803=== CONT TestIsValidCachePath804=== RUN TestIsValidCachePath/narinfo805=== PAUSE TestIsValidCachePath/narinfo806=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars807=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars808=== RUN TestIsValidCachePath/nar_zst809=== PAUSE TestIsValidCachePath/nar_zst810=== RUN TestIsValidCachePath/nar_xz811=== PAUSE TestIsValidCachePath/nar_xz812=== RUN TestIsValidCachePath/nar_bz2813=== PAUSE TestIsValidCachePath/nar_bz2814=== RUN TestIsValidCachePath/nar_uncompressed815=== PAUSE TestIsValidCachePath/nar_uncompressed816=== RUN TestIsValidCachePath/ls817=== PAUSE TestIsValidCachePath/ls818=== RUN TestIsValidCachePath/log819=== PAUSE TestIsValidCachePath/log820=== RUN TestIsValidCachePath/realisation821=== PAUSE TestIsValidCachePath/realisation822=== RUN TestIsValidCachePath/nix-cache-info823=== PAUSE TestIsValidCachePath/nix-cache-info824=== RUN TestIsValidCachePath/index.html825=== PAUSE TestIsValidCachePath/index.html826=== RUN TestIsValidCachePath/traversal_parent827=== PAUSE TestIsValidCachePath/traversal_parent828=== RUN TestIsValidCachePath/traversal_in_middle829=== PAUSE TestIsValidCachePath/traversal_in_middle830=== RUN TestIsValidCachePath/invalid_char_e831=== PAUSE TestIsValidCachePath/invalid_char_e832=== RUN TestIsValidCachePath/invalid_char_u833=== PAUSE TestIsValidCachePath/invalid_char_u834=== RUN TestIsValidCachePath/random_path835=== PAUSE TestIsValidCachePath/random_path836=== RUN TestIsValidCachePath/empty837=== PAUSE TestIsValidCachePath/empty838=== RUN TestIsValidCachePath/leading_slash839=== PAUSE TestIsValidCachePath/leading_slash840=== RUN TestIsValidCachePath/wrong_extension841=== PAUSE TestIsValidCachePath/wrong_extension842=== RUN TestIsValidCachePath/short_hash843=== PAUSE TestIsValidCachePath/short_hash844=== CONT TestProxyHeadersOnlyTrustedOnSocket8452026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures8462026/10/06 21:13:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"847--- PASS: TestService_AuthMiddleware (0.39s)848=== CONT TestParseSingleRange849=== RUN TestParseSingleRange/none850=== PAUSE TestParseSingleRange/none851=== RUN TestParseSingleRange/unknown_unit852=== PAUSE TestParseSingleRange/unknown_unit853=== RUN TestParseSingleRange/multi-range_ignored854=== PAUSE TestParseSingleRange/multi-range_ignored855=== RUN TestParseSingleRange/malformed_no_dash856=== PAUSE TestParseSingleRange/malformed_no_dash857=== RUN TestParseSingleRange/malformed_both_empty858=== PAUSE TestParseSingleRange/malformed_both_empty859=== RUN TestParseSingleRange/malformed_end_before_start860=== PAUSE TestParseSingleRange/malformed_end_before_start861=== RUN TestParseSingleRange/closed862=== PAUSE TestParseSingleRange/closed863=== RUN TestParseSingleRange/open-ended864=== PAUSE TestParseSingleRange/open-ended865=== RUN TestParseSingleRange/end_clamped_to_size866=== PAUSE TestParseSingleRange/end_clamped_to_size867=== RUN TestParseSingleRange/suffix868=== PAUSE TestParseSingleRange/suffix869=== RUN TestParseSingleRange/suffix_exceeds_size870=== PAUSE TestParseSingleRange/suffix_exceeds_size871=== RUN TestParseSingleRange/single_byte872=== PAUSE TestParseSingleRange/single_byte873=== RUN TestParseSingleRange/start_past_EOF874=== PAUSE TestParseSingleRange/start_past_EOF875=== RUN TestParseSingleRange/start_far_past_EOF876=== PAUSE TestParseSingleRange/start_far_past_EOF877=== CONT TestPresentNotReportedWhileGCDeletesClosure878=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale879=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale880=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh881=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh8822026/10/06 21:13:01 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst883=== CONT TestPresentRefreshesOnlyStaleClosures8842026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures885--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.40s)886=== CONT TestPresentReportsOnlyClosureRoots887--- PASS: TestReadRedirectNar (0.43s)888=== CONT TestCreatePin_ReservedPins8892026/10/06 21:13:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8902026/10/06 21:13:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46341/oidc8912026/10/06 21:13:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst892--- PASS: TestCompleteMultipartUnregistered (0.46s)893=== CONT TestOrphanedObjectsGCStressTest8942026/10/06 21:13:01 INFO Received push request method=POST path=/api/pushes895--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.50s)896=== CONT TestOrphanedObjectsGC8972026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures8982026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures8992026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures900--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.53s)901=== CONT TestObjectStatsTrigger9022026/10/06 21:13:01 INFO Received cleanup request method=DELETE path=/api/pending_closures9032026/10/06 21:13:01 INFO Aborted multipart uploads count=0 kept=09042026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures9052026/10/06 21:13:01 INFO Received cleanup request method=DELETE path=/api/pending_closures9062026/10/06 21:13:01 INFO Aborted multipart uploads count=1 kept=09072026/10/06 21:13:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9082026-10-06 21:13:01.757 UTC [665] ERROR: Closure does not exist: id=19092026-10-06 21:13:01.757 UTC [665] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9102026-10-06 21:13:01.757 UTC [665] STATEMENT: -- name: CommitPendingClosure :exec911 SELECT commit_pending_closure($1::bigint)912 913--- PASS: TestService_cleanupPendingClosuresHandler (0.58s)914=== CONT TestPendingCleanupUsesOneCutoff9152026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures9162026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures917--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.62s)918=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded919--- PASS: TestReadRedirectKeepsNarinfoProxied (0.64s)920=== CONT TestMultipartCleanup921--- PASS: TestReadRedirectUsesPublicS3URL (0.67s)922=== CONT TestServerTLSConfig923=== RUN TestServerTLSConfig/no_client_CA924=== PAUSE TestServerTLSConfig/no_client_CA925=== RUN TestServerTLSConfig/missing_CA_file926=== PAUSE TestServerTLSConfig/missing_CA_file927=== RUN TestServerTLSConfig/not_a_PEM_file928=== PAUSE TestServerTLSConfig/not_a_PEM_file929=== CONT TestService_NativeMTLS930--- PASS: TestReadProxyDisabled (0.68s)931=== CONT TestMetricsInventory932--- PASS: TestReadProxyNarStreaming (0.63s)933=== CONT TestNARDeduplicationMetadataUploadBug934--- PASS: TestReadProxyInvalidPath (0.72s)935=== CONT TestCreatePendingClosureRejectsOversizedNAR9362026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures937--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)938=== CONT TestCacheConfigHandlerMaxNarSize939--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)940=== CONT TestGenerateLandingPage941--- PASS: TestGenerateLandingPage (0.01s)942=== CONT TestService_readinessHandler943--- PASS: TestService_Rustfstest (0.77s)944=== CONT TestService_healthCheckHandler9452026/10/06 21:13:01 INFO Received uploads request method=POST path=/api/pending_closures946--- PASS: TestReadProxyRangeRequest (0.84s)947=== CONT TestGracefulShutdownDrainsInflight9482026/10/06 21:13:02 INFO Starting HTTP server address=127.0.0.1:408379492026/10/06 21:13:02 INFO Shutdown signal received, draining in-flight requests timeout=10s950--- PASS: TestReadProxy404 (0.81s)951=== CONT TestGCTaskStore_Fail952--- PASS: TestGCTaskStore_Fail (0.00s)953=== CONT TestGCTaskStore_PhaseUpdates954--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)955=== CONT TestGCTaskStore_CompletedAllowsNewTask956--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)957=== CONT TestGCTaskStore_GetReturnsLatest958--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)959=== CONT TestGCTaskStore_GetEmpty960--- PASS: TestGCTaskStore_GetEmpty (0.00s)961=== CONT TestGCTaskStore_ConflictDifferentParams962--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)963=== CONT TestGCTaskStore_DeduplicateSameParams964--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)965=== CONT TestGCTaskStore_StartNew966--- PASS: TestGCTaskStore_StartNew (0.00s)967=== CONT TestGCEndsOnShutdown968=== RUN TestGCEndsOnShutdown/before_the_run9692026/10/06 21:13:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete970=== PAUSE TestGCEndsOnShutdown/before_the_run971=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete972=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete973=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark974=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark975=== CONT TestConnectWaitsForAPeerMigration9762026/10/06 21:13:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9772026/10/06 21:13:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLjIxYjJkZmRhLTViNWItNDlmYy04NmI0LTNhYTQyZDE1YmM5NHgxNzkxMzIxMTgxNjg3OTE3MDA0 parts=109782026/10/06 21:13:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete979--- PASS: TestGracefulShutdownDrainsInflight (0.07s)980=== CONT TestPushWaitsForSweepHoldingRow9812026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=09822026/10/06 21:13:02 WARN Force mode enabled - objects will be deleted immediately without grace period9832026/10/06 21:13:02 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=09842026/10/06 21:13:02 INFO Completed upload id=19852026/10/06 21:13:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009862026/10/06 21:13:02 INFO Vacuumed table table=pending_closures9872026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/06 21:13:02 INFO Vacuumed table table=pending_objects9892026/10/06 21:13:02 INFO Vacuumed table table=multipart_uploads990--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.87s)991=== CONT TestSweepRechecksPendingAfterLocking9922026/10/06 21:13:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures9932026/10/06 21:13:02 INFO Vacuumed table table=closures9942026/10/06 21:13:02 INFO Vacuumed table table=objects995--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.96s)996=== CONT TestGetExistingObjectsLocksRows9972026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=09982026/10/06 21:13:02 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=09992026/10/06 21:13:02 INFO Vacuumed table table=pending_closures10002026/10/06 21:13:02 INFO Vacuumed table table=pending_objects10012026/10/06 21:13:02 INFO Vacuumed table table=multipart_uploads10022026/10/06 21:13:02 INFO Vacuumed table table=closures10032026/10/06 21:13:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10042026/10/06 21:13:02 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1005--- PASS: TestReadProxyNarinfo (0.82s)1006=== CONT TestRegisterCompletedObjectNeedsPendingRow10072026/10/06 21:13:02 INFO Vacuumed table table=objects10082026/10/06 21:13:02 INFO Starting HTTP server address=127.0.0.1:4391710092026/10/06 21:13:02 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3107572404/001/proxy.sock10102026/10/06 21:13:02 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10112026/10/06 21:13:02 INFO Shutdown signal received, draining in-flight requests timeout=10s1012--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.64s)1013=== CONT TestSweepSkipsRowsLockedByPush10142026/10/06 21:13:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001015--- PASS: TestService_createPendingClosureHandler (1.01s)1016=== CONT TestFailedS3DeleteKeepsTombstone10172026/10/06 21:13:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLmJjNGJiZmVhLTUxMjYtNGE0NC1hY2ExLTg0ZmQzN2M1NzNkMngxNzkxMzIxMTgxNzY0NzY3Njkz parts=1010182026/10/06 21:13:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10192026/10/06 21:13:02 INFO Completed upload id=110202026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures10212026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures1022--- PASS: TestReadProxyContentNegotiation (0.95s)1023=== CONT TestForceGCDuringPushOffersSweptObject1024=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1025=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1026=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1027=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1028=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10292026/10/06 21:13:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10302026/10/06 21:13:02 WARN Found objects in DB but missing from S3, will re-upload count=11031--- PASS: TestService_verifyS3Integrity (1.03s)1032=== CONT TestGCSweepDeliversEachKeyOnce1033--- PASS: TestPresentReportsOnlyClosureRoots (0.66s)1034=== CONT TestTombstonedObjectOfferedWithoutWaiting1035--- PASS: TestPresentRefreshesOnlyStaleClosures (0.68s)1036=== CONT TestGCSweepSkipsPendingObjects10372026/10/06 21:13:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10382026/10/06 21:13:02 WARN Refused reserved pin name=worker-x86_64-linux10392026/10/06 21:13:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10402026/10/06 21:13:02 INFO Received create pin request method=POST path=/api/pins/my-app10412026/10/06 21:13:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1042--- PASS: TestCreatePin_ReservedPins (0.68s)1043=== CONT TestDeduplicatedObjectsRecordedAsPending1044--- PASS: TestObjectStatsTrigger (0.67s)10452026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures1046=== CONT TestPushDedupSurvivesConcurrentGC10472026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures10482026/10/06 21:13:02 INFO Received cleanup request method=DELETE path=/api/pending_closures10492026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures1050--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.62s)1051=== CONT TestGCMetrics10522026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures1053--- PASS: TestMetricsInventory (0.62s)1054=== CONT TestGCBugBareHashReferences10552026/10/06 21:13:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10562026/10/06 21:13:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1057--- PASS: TestService_NativeMTLS (0.63s)1058=== CONT TestGCAdvisoryLockBlocksConcurrentRun10592026/10/06 21:13:02 WARN readiness check failed error="closed pool"1060--- PASS: TestService_readinessHandler (0.63s)1061=== CONT TestLeadEndsOnShutdown10622026/10/06 21:13:02 INFO Received cleanup request method=DELETE path=/api/pending_closures10632026/10/06 21:13:02 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket36/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10642026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=110652026/10/06 21:13:02 INFO Received cleanup request method=DELETE path=/api/pending_closures1066=== NAME TestNARDeduplicationMetadataUploadBug1067 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug472609085/001/store/rp482favqbdfkbl0ygyn12pvw232b96r-file1.txt10682026/10/06 21:13:02 INFO Aborted multipart uploads count=1 kept=01069--- PASS: TestMultipartCleanup (0.74s)1070=== CONT TestLeadIncumbentAnnouncesAtOnce1071--- PASS: TestService_healthCheckHandler (0.63s)1072=== CONT TestLeadElectsOneAndHandsOver10732026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures10742026/10/06 21:13:02 INFO Received push request method=POST path=/api/pushes10752026/10/06 21:13:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10762026/10/06 21:13:02 INFO Uploading rp482favqbdfkbl0ygyn12pvw232b96r-file1.txt (160B)1077=== NAME TestOrphanedObjectsGC1078 orphaned_objects_gc_test.go:290: GC Test Summary:1079 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1080 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1081 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1082 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1083 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1084--- PASS: TestOrphanedObjectsGC (0.99s)1085=== CONT TestClientErrorHandling1086=== RUN TestClientErrorHandling/InvalidStorePath1087=== PAUSE TestClientErrorHandling/InvalidStorePath1088=== RUN TestClientErrorHandling/InvalidAuthToken1089=== PAUSE TestClientErrorHandling/InvalidAuthToken1090=== RUN TestClientErrorHandling/ServerNotAvailable1091=== PAUSE TestClientErrorHandling/ServerNotAvailable1092=== CONT TestResolveDBConnectionString1093=== RUN TestResolveDBConnectionString/flag_wins1094=== PAUSE TestResolveDBConnectionString/flag_wins1095=== RUN TestResolveDBConnectionString/file_when_flag_empty1096=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1097=== RUN TestResolveDBConnectionString/missing_file_is_an_error1098=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1099=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1100=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1101=== RUN TestResolveDBConnectionString/nothing_configured1102=== PAUSE TestResolveDBConnectionString/nothing_configured1103=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11042026/10/06 21:13:02 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11052026/10/06 21:13:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11062026/10/06 21:13:02 WARN Failed to register uploaded object key=rp482favqbdfkbl0ygyn12pvw232b96r.ls error="server returned 404: 404 page not found\n"11072026/10/06 21:13:02 INFO Signed narinfos id=1 count=111082026/10/06 21:13:02 INFO Uploading 1 narinfos11092026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=011102026/10/06 21:13:02 INFO Received complete push request method=POST path=/api/pushes/1/complete11112026/10/06 21:13:02 WARN Failed to register uploaded object key=rp482favqbdfkbl0ygyn12pvw232b96r.narinfo error="server returned 404: 404 page not found\n"11122026/10/06 21:13:02 WARN Force mode enabled - objects will be deleted immediately without grace period11132026/10/06 21:13:02 INFO Upload complete. (77ms)1114=== NAME TestNARDeduplicationMetadataUploadBug1115 metadata_upload_test.go:54: Retrieved narinfo from S3:1116 StorePath: /build/TestNARDeduplicationMetadataUploadBug472609085/001/store/rp482favqbdfkbl0ygyn12pvw232b96r-file1.txt1117 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1118 Compression: zstd1119 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1120 NarSize: 1601121 References: 1122 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1123 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1124 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1125 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11262026/10/06 21:13:02 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=011272026/10/06 21:13:02 INFO Vacuumed table table=pending_closures11282026/10/06 21:13:02 INFO Vacuumed table table=pending_objects11292026/10/06 21:13:02 INFO Vacuumed table table=multipart_uploads11302026/10/06 21:13:02 INFO Vacuumed table table=closures11312026/10/06 21:13:02 INFO Vacuumed table table=objects1132--- PASS: TestSweepRechecksPendingAfterLocking (0.57s)1133=== CONT TestClientFallsBackToClosures1134--- PASS: TestGetExistingObjectsLocksRows (0.58s)1135=== CONT TestClientPushesUseOnePush1136=== NAME TestNARDeduplicationMetadataUploadBug1137 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug472609085/001/store/5yf11nmzjk13a45kvqm73hn2pawngjra-file2.txt1138--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.57s)1139=== CONT TestPinProtectsFromGC11402026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures11412026/10/06 21:13:02 INFO Received push request method=POST path=/api/pushes11422026/10/06 21:13:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11432026/10/06 21:13:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11442026/10/06 21:13:02 WARN Failed to register uploaded object key=5yf11nmzjk13a45kvqm73hn2pawngjra.ls error="server returned 404: 404 page not found\n"11452026/10/06 21:13:02 INFO Signed narinfos id=2 count=111462026/10/06 21:13:02 INFO Uploading 1 narinfos11472026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=011482026/10/06 21:13:02 INFO Received complete push request method=POST path=/api/pushes/2/complete11492026/10/06 21:13:02 WARN Failed to register uploaded object key=5yf11nmzjk13a45kvqm73hn2pawngjra.narinfo error="server returned 404: 404 page not found\n"11502026/10/06 21:13:02 WARN Force mode enabled - objects will be deleted immediately without grace period11512026/10/06 21:13:02 INFO Upload complete. (55ms)1152=== NAME TestNARDeduplicationMetadataUploadBug1153 metadata_upload_test.go:76: Retrieved narinfo from S3:1154 StorePath: /build/TestNARDeduplicationMetadataUploadBug472609085/001/store/5yf11nmzjk13a45kvqm73hn2pawngjra-file2.txt1155 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1156 Compression: zstd1157 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1158 NarSize: 1601159 References: 1160 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11612026/10/06 21:13:02 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=01162 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1163 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):11642026/10/06 21:13:02 INFO Vacuumed table table=pending_closures1165 {"version":1,"root":{"type":"regular","size":44}}11662026/10/06 21:13:02 INFO Vacuumed table table=pending_objects11672026/10/06 21:13:02 INFO Vacuumed table table=multipart_uploads11682026/10/06 21:13:02 INFO Vacuumed table table=closures11692026/10/06 21:13:02 INFO Vacuumed table table=objects1170--- PASS: TestNARDeduplicationMetadataUploadBug (0.94s)1171=== CONT TestClientSharedPathCommittedMidPush11722026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=011732026/10/06 21:13:02 WARN Force mode enabled - objects will be deleted immediately without grace period11742026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=011752026/10/06 21:13:02 WARN Force mode enabled - objects will be deleted immediately without grace period11762026/10/06 21:13:02 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=011772026/10/06 21:13:02 INFO Vacuumed table table=pending_closures11782026/10/06 21:13:02 INFO Vacuumed table table=pending_objects11792026/10/06 21:13:02 INFO Vacuumed table table=multipart_uploads11802026/10/06 21:13:02 INFO Vacuumed table table=closures11812026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures11822026/10/06 21:13:02 INFO Vacuumed table table=objects11832026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=01184--- PASS: TestSweepSkipsRowsLockedByPush (0.67s)1185=== CONT TestClientWithDependencies11862026/10/06 21:13:02 WARN Force mode enabled - objects will be deleted immediately without grace period11872026/10/06 21:13:02 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=011882026/10/06 21:13:02 INFO Vacuumed table table=pending_closures11892026/10/06 21:13:02 INFO Vacuumed table table=pending_objects11902026/10/06 21:13:02 INFO Vacuumed table table=multipart_uploads11912026/10/06 21:13:02 INFO Vacuumed table table=closures11922026/10/06 21:13:02 INFO Vacuumed table table=objects1193--- PASS: TestGCSweepDeliversEachKeyOnce (0.66s)1194=== CONT TestClientMultipleUploads11952026/10/06 21:13:02 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11962026/10/06 21:13:02 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1197--- PASS: TestFailedS3DeleteKeepsTombstone (0.68s)1198=== CONT TestClientIntegration11992026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures1200--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.65s)1201=== CONT TestReadProxyConditionalGet12022026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures12032026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures12042026/10/06 21:13:02 INFO Aborted multipart uploads count=0 kept=012052026/10/06 21:13:02 WARN Force mode enabled - objects will be deleted immediately without grace period12062026/10/06 21:13:02 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=01207--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.68s)1208=== CONT TestPush_SignsNarinfosOfItsPendingObjects12092026/10/06 21:13:02 INFO Vacuumed table table=pending_closures12102026/10/06 21:13:02 INFO Vacuumed table table=pending_objects12112026/10/06 21:13:02 INFO Vacuumed table table=multipart_uploads12122026/10/06 21:13:02 INFO Vacuumed table table=closures12132026/10/06 21:13:02 INFO Vacuumed table table=objects1214--- PASS: TestGCSweepSkipsPendingObjects (0.73s)1215=== CONT TestCompletedNarNotReofferedAcrossClosures12162026/10/06 21:13:02 INFO Received uploads request method=POST path=/api/pending_closures12172026/10/06 21:13:03 INFO Aborted multipart uploads count=0 kept=012182026/10/06 21:13:03 WARN Force mode enabled - objects will be deleted immediately without grace period12192026/10/06 21:13:03 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=012202026/10/06 21:13:03 INFO Vacuumed table table=pending_closures12212026/10/06 21:13:03 INFO Vacuumed table table=pending_objects12222026/10/06 21:13:03 INFO Vacuumed table table=multipart_uploads12232026/10/06 21:13:03 INFO Vacuumed table table=closures12242026/10/06 21:13:03 INFO Vacuumed table table=objects1225--- PASS: TestGCMetrics (0.60s)1226=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1227--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.85s)1228=== CONT TestRedundantMultipartUpload12292026/10/06 21:13:03 INFO Aborted multipart uploads count=0 kept=012302026/10/06 21:13:03 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"1231--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.59s)1232=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit12332026/10/06 21:13:03 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=012342026/10/06 21:13:03 INFO Vacuumed table table=pending_closures12352026/10/06 21:13:03 INFO Vacuumed table table=pending_objects12362026/10/06 21:13:03 INFO Vacuumed table table=multipart_uploads12372026/10/06 21:13:03 INFO Vacuumed table table=closures12382026/10/06 21:13:03 INFO Vacuumed table table=objects12392026/10/06 21:13:03 INFO lead: acquired remote=192.0.2.1:123412402026/10/06 21:13:03 INFO Aborted multipart uploads count=0 kept=012412026/10/06 21:13:03 WARN Force mode enabled - objects will be deleted immediately without grace period12422026/10/06 21:13:03 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=012432026/10/06 21:13:03 INFO Vacuumed table table=pending_closures12442026/10/06 21:13:03 INFO Vacuumed table table=pending_objects12452026/10/06 21:13:03 INFO Vacuumed table table=multipart_uploads12462026/10/06 21:13:03 INFO Vacuumed table table=closures1247--- PASS: TestPushWaitsForSweepHoldingRow (1.02s)1248=== CONT TestPush_RejectsBadRequests12492026/10/06 21:13:03 INFO Vacuumed table table=objects1250--- PASS: TestPushDedupSurvivesConcurrentGC (0.74s)1251=== CONT TestPush_CompleteCommitsEveryRoot12522026/10/06 21:13:03 INFO lead: acquired remote=192.0.2.1:123412532026/10/06 21:13:03 INFO lead: released remote=192.0.2.1:12341254--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.58s)1255=== CONT TestCacheStatsHandler12562026/10/06 21:13:03 INFO lead: acquired remote=192.0.2.1:12341257--- PASS: TestGCBugBareHashReferences (0.80s)1258=== CONT TestClientCADerivations1259=== NAME TestPinProtectsFromGC1260 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2530032632/001/store/7w1b1ppdm6dkx8vywy06wwdc9rwgxh44-pinned-file.txt1261 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2530032632/001/store/712x15761s0ylp3nli5yd0vgfxqgvhj5-unpinned-file.txt1262=== NAME TestClientMultipleUploads1263 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3251310710/001/store/ipa3fqsj4f91q9b3mayr3kxdx3p9xh38-test-file-0.txt12642026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes1265--- PASS: TestReadProxyConditionalGet (0.51s)1266=== CONT TestReadProxyOutlastsServerWriteTimeout12672026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12682026/10/06 21:13:03 INFO Signed narinfos id=1 count=112692026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12702026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12712026/10/06 21:13:03 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12722026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12732026/10/06 21:13:03 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12742026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12752026/10/06 21:13:03 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112762026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1277=== NAME TestClientIntegration12782026/10/06 21:13:03 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1279 client_integration_test.go:286: Created store path: /build/TestClientIntegration2643402279/002/store/k08api7q3ibbnx0rfq64hw106wkfw68v-test-file.txt1280--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.45s)1281=== CONT TestService_ReadAuthMiddleware12822026/10/06 21:13:03 INFO Received uploads request method=POST path=/api/pending_closures1283=== NAME TestClientMultipleUploads1284 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3251310710/001/store/i5vsv8636ll3affp6ay06ar84sapasaf-test-file-1.txt1285=== NAME TestClientWithDependencies1286 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies640607193/001/store/ipy0rp4yrp68p0w6k9spfh94xqd6gkyz-test-script12872026/10/06 21:13:03 INFO Received uploads request method=POST path=/api/pending_closures12882026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes12892026/10/06 21:13:03 INFO Received uploads request method=POST path=/api/pending_closures12902026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes12912026/10/06 21:13:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12922026/10/06 21:13:03 INFO Uploading 7w1b1ppdm6dkx8vywy06wwdc9rwgxh44-pinned-file.txt (128B)12932026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes12942026/10/06 21:13:03 INFO Received uploads request method=POST path=/api/pending_closures12952026/10/06 21:13:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12962026/10/06 21:13:03 INFO Uploading 4m2yfb7blf3bna5jd9iskmjaxmsnr4km-top (224B)12972026/10/06 21:13:03 INFO Uploading vjakkg437p5lhsdry9h1r4ppy6in7v0k-shared-dep (136B)12982026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12992026/10/06 21:13:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13002026/10/06 21:13:03 INFO Uploading j1ncr5nlf4pzy59y3sjbvfkvgj81dmbv-a (216B)13012026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13022026/10/06 21:13:03 INFO Uploading dalajdimp56y80hjh3bra55yhc6xj05b-shared-dep (136B)13032026/10/06 21:13:03 WARN Failed to register uploaded object key=7w1b1ppdm6dkx8vywy06wwdc9rwgxh44.ls error="server returned 404: 404 page not found\n"13042026/10/06 21:13:03 INFO Signed narinfos id=1 count=113052026/10/06 21:13:03 INFO Uploading 1 narinfos1306 client_integration_test.go:615: Found 1 dependencies (including self)1307=== NAME TestClientMultipleUploads1308 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3251310710/001/store/0d7hab4b100zhkldk2waqd0z9p9ah88c-test-file-2.txt13092026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13102026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1xji8x7c36mgy0g9pqkh4kyynvc4jf08dzzrrq27iwdw1fg18py6.nar.zst error="server returned 404: 404 page not found\n"13112026/10/06 21:13:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13122026/10/06 21:13:03 WARN Failed to register uploaded object key=vjakkg437p5lhsdry9h1r4ppy6in7v0k.ls error="server returned 404: 404 page not found\n"13132026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13142026/10/06 21:13:03 WARN Failed to register uploaded object key=4m2yfb7blf3bna5jd9iskmjaxmsnr4km.ls error="server returned 404: 404 page not found\n"13152026/10/06 21:13:03 INFO Signed narinfos id=1 count=213162026/10/06 21:13:03 INFO Uploading 2 narinfos13172026/10/06 21:13:03 WARN Failed to register uploaded object key=gflkvh914328vvvbgpr6k3a13cfk73lg.ls error="server returned 404: 404 page not found\n"13182026/10/06 21:13:03 WARN Failed to register uploaded object key=j1ncr5nlf4pzy59y3sjbvfkvgj81dmbv.ls error="server returned 404: 404 page not found\n"13192026/10/06 21:13:03 WARN Failed to register uploaded object key=dalajdimp56y80hjh3bra55yhc6xj05b.ls error="server returned 404: 404 page not found\n"13202026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13212026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1861nk6zfyzvcfwmbr9rfwiksa08lqwmxgfcjmb6blvi0bdxvcri.nar.zst error="server returned 404: 404 page not found\n"13222026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13232026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13242026/10/06 21:13:03 WARN Failed to register uploaded object key=7w1b1ppdm6dkx8vywy06wwdc9rwgxh44.narinfo error="server returned 404: 404 page not found\n"13252026/10/06 21:13:03 INFO Signed narinfos id=2 count=213262026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13272026/10/06 21:13:03 INFO Signed narinfos id=1 count=213282026/10/06 21:13:03 INFO Uploading 4 narinfos13292026/10/06 21:13:03 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLjVkYTBiZDViLWI2MjctNGIzOC04YTFhLTk3YWI5MWJjM2ViMngxNzkxMzIxMTgzNDM4NTMxODQ413302026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13312026/10/06 21:13:03 WARN Failed to register uploaded object key=vjakkg437p5lhsdry9h1r4ppy6in7v0k.narinfo error="server returned 404: 404 page not found\n"13322026/10/06 21:13:03 WARN Failed to register uploaded object key=4m2yfb7blf3bna5jd9iskmjaxmsnr4km.narinfo error="server returned 404: 404 page not found\n"13332026/10/06 21:13:03 WARN Failed to register uploaded object key=gflkvh914328vvvbgpr6k3a13cfk73lg.narinfo error="server returned 404: 404 page not found\n"13342026/10/06 21:13:03 WARN Failed to register uploaded object key=j1ncr5nlf4pzy59y3sjbvfkvgj81dmbv.narinfo error="server returned 404: 404 page not found\n"13352026/10/06 21:13:03 WARN Failed to register uploaded object key=dalajdimp56y80hjh3bra55yhc6xj05b.narinfo error="server returned 404: 404 page not found\n"13362026/10/06 21:13:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13372026/10/06 21:13:03 WARN Failed to register uploaded object key=dalajdimp56y80hjh3bra55yhc6xj05b.narinfo error="server returned 404: 404 page not found\n"13382026/10/06 21:13:03 INFO Upload complete. (61ms)13392026/10/06 21:13:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLjVkYTBiZDViLWI2MjctNGIzOC04YTFhLTk3YWI5MWJjM2ViMngxNzkxMzIxMTgzNDM4NTMxODQ4 parts=113402026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13412026/10/06 21:13:03 INFO Upload complete. (69ms)1342=== NAME TestClientSharedPathCommittedMidPush1343 client_integration_test.go:680: Retrieved narinfo from S3:1344 StorePath: /build/TestClientSharedPathCommittedMidPush883174596/001/store/vjakkg437p5lhsdry9h1r4ppy6in7v0k-shared-dep1345 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1346 Compression: zstd1347 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821348 NarSize: 1361349 References: 1350 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1351--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.45s)1352=== CONT TestService_AuthMiddleware_OIDC1353=== NAME TestClientSharedPathCommittedMidPush1354 client_integration_test.go:680: Retrieved narinfo from S3:1355 StorePath: /build/TestClientSharedPathCommittedMidPush883174596/001/store/4m2yfb7blf3bna5jd9iskmjaxmsnr4km-top1356 URL: nar/1xji8x7c36mgy0g9pqkh4kyynvc4jf08dzzrrq27iwdw1fg18py6.nar.zst1357 Compression: zstd1358 NarHash: sha256:1xji8x7c36mgy0g9pqkh4kyynvc4jf08dzzrrq27iwdw1fg18py61359 NarSize: 2241360 References: /build/TestClientSharedPathCommittedMidPush883174596/001/store/vjakkg437p5lhsdry9h1r4ppy6in7v0k-shared-dep1361 CA: text:sha256:1k2lfql8fymz3g43cvdb1s9inppp1sb99rw2gzfndcbjkflns6p813622026/10/06 21:13:03 INFO Completed upload id=113632026/10/06 21:13:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13642026/10/06 21:13:03 INFO Received uploads request method=POST path=/api/pending_closures13652026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes1366--- PASS: TestClientSharedPathCommittedMidPush (0.66s)1367=== CONT TestCacheConfigHandler1368=== RUN TestCacheConfigHandler/full_config,_no_issuer1369=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1370=== RUN TestCacheConfigHandler/no_cache_url_configured1371=== PAUSE TestCacheConfigHandler/no_cache_url_configured1372=== RUN TestCacheConfigHandler/no_signing_keys1373=== PAUSE TestCacheConfigHandler/no_signing_keys1374=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1375=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1376=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13772026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes13782026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes13792026/10/06 21:13:03 INFO Completed upload id=213802026/10/06 21:13:03 INFO Upload complete. (88ms)13812026/10/06 21:13:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13822026/10/06 21:13:03 INFO Uploading k08api7q3ibbnx0rfq64hw106wkfw68v-test-file.txt (152B)1383=== NAME TestClientFallsBackToClosures1384 client_pushes_test.go:112: Retrieved narinfo from S3:1385 StorePath: /build/TestClientFallsBackToClosures1031023394/001/store/dalajdimp56y80hjh3bra55yhc6xj05b-shared-dep1386 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1387 Compression: zstd1388 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821389 NarSize: 1361390 References: 1391 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1392 client_pushes_test.go:112: Retrieved narinfo from S3:1393 StorePath: /build/TestClientFallsBackToClosures1031023394/001/store/j1ncr5nlf4pzy59y3sjbvfkvgj81dmbv-a1394 URL: nar/1861nk6zfyzvcfwmbr9rfwiksa08lqwmxgfcjmb6blvi0bdxvcri.nar.zst1395 Compression: zstd1396 NarHash: sha256:1861nk6zfyzvcfwmbr9rfwiksa08lqwmxgfcjmb6blvi0bdxvcri1397 NarSize: 2161398 References: /build/TestClientFallsBackToClosures1031023394/001/store/dalajdimp56y80hjh3bra55yhc6xj05b-shared-dep1399 CA: text:sha256:012dd401jngzf932k3q7i5wr834vgz0szpm5d9p3kplgy5v1yp8k14002026/10/06 21:13:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14012026/10/06 21:13:03 INFO Uploading w5akmsj4q2a6ml4mih8i28izl8855g8a-a (208B)14022026/10/06 21:13:03 INFO Uploading zbhd5fj21h3wsb2vwsnp3f7rrlm55n30-shared-dep (136B)14032026/10/06 21:13:03 WARN Failed to register uploaded object key=k08api7q3ibbnx0rfq64hw106wkfw68v.ls error="server returned 404: 404 page not found\n"1404 client_pushes_test.go:112: Retrieved narinfo from S3:14052026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1406 StorePath: /build/TestClientFallsBackToClosures1031023394/001/store/gflkvh914328vvvbgpr6k3a13cfk73lg-b1407 URL: nar/1861nk6zfyzvcfwmbr9rfwiksa08lqwmxgfcjmb6blvi0bdxvcri.nar.zst1408 Compression: zstd14092026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1410 NarHash: sha256:1861nk6zfyzvcfwmbr9rfwiksa08lqwmxgfcjmb6blvi0bdxvcri1411 NarSize: 2161412 References: /build/TestClientFallsBackToClosures1031023394/001/store/dalajdimp56y80hjh3bra55yhc6xj05b-shared-dep1413 CA: text:sha256:012dd401jngzf932k3q7i5wr834vgz0szpm5d9p3kplgy5v1yp8k14142026/10/06 21:13:03 INFO Received uploads request method=POST path=/api/pending_closures14152026/10/06 21:13:03 INFO Signed narinfos id=1 count=114162026/10/06 21:13:03 INFO Uploading 1 narinfos14172026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1pvvz90zzq8sw0jsvwl3m6h66js37dmfziqvcyixn47gf01nyhwl.nar.zst error="server returned 404: 404 page not found\n"14182026/10/06 21:13:03 WARN Failed to register uploaded object key=vnddva5md40laklng19qczrba2bpli2i.ls error="server returned 404: 404 page not found\n"14192026/10/06 21:13:03 WARN Failed to register uploaded object key=zbhd5fj21h3wsb2vwsnp3f7rrlm55n30.ls error="server returned 404: 404 page not found\n"14202026/10/06 21:13:03 WARN Failed to register uploaded object key=w5akmsj4q2a6ml4mih8i28izl8855g8a.ls error="server returned 404: 404 page not found\n"14212026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14222026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14232026/10/06 21:13:03 INFO Signed narinfos id=1 count=314242026/10/06 21:13:03 INFO Uploading 3 narinfos1425--- PASS: TestClientFallsBackToClosures (0.80s)1426=== CONT TestService_AuthMiddleware_MTLSProxyHeader14272026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14282026/10/06 21:13:03 WARN Failed to register uploaded object key=k08api7q3ibbnx0rfq64hw106wkfw68v.narinfo error="server returned 404: 404 page not found\n"1429=== RUN TestPush_RejectsBadRequests/no_roots1430=== PAUSE TestPush_RejectsBadRequests/no_roots1431=== RUN TestPush_RejectsBadRequests/no_objects14322026/10/06 21:13:03 WARN Failed to register uploaded object key=w5akmsj4q2a6ml4mih8i28izl8855g8a.narinfo error="server returned 404: 404 page not found\n"1433=== PAUSE TestPush_RejectsBadRequests/no_objects1434=== RUN TestPush_RejectsBadRequests/bad_root1435=== PAUSE TestPush_RejectsBadRequests/bad_root1436=== RUN TestPush_RejectsBadRequests/root_not_in_objects1437=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1438=== CONT TestService_ReadScope_PublicByDefault14392026/10/06 21:13:03 WARN Failed to register uploaded object key=zbhd5fj21h3wsb2vwsnp3f7rrlm55n30.narinfo error="server returned 404: 404 page not found\n"14402026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14412026/10/06 21:13:03 WARN Failed to register uploaded object key=vnddva5md40laklng19qczrba2bpli2i.narinfo error="server returned 404: 404 page not found\n"14422026/10/06 21:13:03 INFO Upload complete. (70ms)14432026/10/06 21:13:03 INFO Upload complete. (67ms)1444=== NAME TestClientPushesUseOnePush1445 client_pushes_test.go:97: Retrieved narinfo from S3:1446 StorePath: /build/TestClientPushesUseOnePush301208397/001/store/zbhd5fj21h3wsb2vwsnp3f7rrlm55n30-shared-dep1447 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1448 Compression: zstd1449 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821450 NarSize: 1361451 References: 1452 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1453 client_pushes_test.go:97: Retrieved narinfo from S3:1454 StorePath: /build/TestClientPushesUseOnePush301208397/001/store/w5akmsj4q2a6ml4mih8i28izl8855g8a-a1455 URL: nar/1pvvz90zzq8sw0jsvwl3m6h66js37dmfziqvcyixn47gf01nyhwl.nar.zst1456 Compression: zstd1457 NarHash: sha256:1pvvz90zzq8sw0jsvwl3m6h66js37dmfziqvcyixn47gf01nyhwl1458 NarSize: 2081459 References: /build/TestClientPushesUseOnePush301208397/001/store/zbhd5fj21h3wsb2vwsnp3f7rrlm55n30-shared-dep1460 CA: text:sha256:1bi9dvkjifi9lbizsmfkbq78ix719l98d9afp0c9230dv6pfaqq31461 client_pushes_test.go:97: Retrieved narinfo from S3:1462 StorePath: /build/TestClientPushesUseOnePush301208397/001/store/vnddva5md40laklng19qczrba2bpli2i-b1463 URL: nar/1pvvz90zzq8sw0jsvwl3m6h66js37dmfziqvcyixn47gf01nyhwl.nar.zst1464 Compression: zstd1465 NarHash: sha256:1pvvz90zzq8sw0jsvwl3m6h66js37dmfziqvcyixn47gf01nyhwl1466 NarSize: 2081467 References: /build/TestClientPushesUseOnePush301208397/001/store/zbhd5fj21h3wsb2vwsnp3f7rrlm55n30-shared-dep1468 CA: text:sha256:1bi9dvkjifi9lbizsmfkbq78ix719l98d9afp0c9230dv6pfaqq31469--- PASS: TestClientPushesUseOnePush (0.80s)1470=== CONT TestService_RequireScope_OIDC14712026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes1472--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.87s)1473=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14742026/10/06 21:13:03 INFO Received uploads request method=POST path=/1475=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14762026/10/06 21:13:03 INFO Received uploads request method=POST path=/1477=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14782026/10/06 21:13:03 INFO Received request for more parts method=POST path=/1479=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14802026/10/06 21:13:03 INFO Received complete multipart upload request method=POST path=/1481--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1482 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1483 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1484 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1485 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1486=== CONT TestPendingClosureWriteTimeout/empty1487=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline14882026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes14892026/10/06 21:13:03 INFO Aborted multipart uploads count=0 kept=014902026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes14912026/10/06 21:13:03 WARN Force mode enabled - objects will be deleted immediately without grace period14922026/10/06 21:13:03 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14932026/10/06 21:13:03 INFO Uploading ipa3fqsj4f91q9b3mayr3kxdx3p9xh38-test-file-0.txt (160B)14942026/10/06 21:13:03 INFO All 1 paths already cached14952026/10/06 21:13:03 INFO Uploading 0d7hab4b100zhkldk2waqd0z9p9ah88c-test-file-2.txt (160B)14962026/10/06 21:13:03 INFO Uploading i5vsv8636ll3affp6ay06ar84sapasaf-test-file-1.txt (160B)14972026/10/06 21:13:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14982026/10/06 21:13:03 INFO Uploading 712x15761s0ylp3nli5yd0vgfxqgvhj5-unpinned-file.txt (128B)1499=== NAME TestClientIntegration1500 client_integration_test.go:312: Retrieved narinfo from S3:1501 StorePath: /build/TestClientIntegration2643402279/002/store/k08api7q3ibbnx0rfq64hw106wkfw68v-test-file.txt1502 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1503 Compression: zstd1504 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11505 NarSize: 1521506 References: 1507 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115082026/10/06 21:13:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37531/oidc15092026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1510 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)15112026/10/06 21:13:03 WARN Failed to register uploaded object key=ipa3fqsj4f91q9b3mayr3kxdx3p9xh38.ls error="server returned 404: 404 page not found\n"1512 client_integration_test.go:313: Decompressed .ls content (64 bytes):1513 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1514 client_integration_test.go:316: Testing garbage collection...15152026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15162026/10/06 21:13:03 WARN Failed to register uploaded object key=i5vsv8636ll3affp6ay06ar84sapasaf.ls error="server returned 404: 404 page not found\n"15172026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15182026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15192026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15202026/10/06 21:13:03 WARN Failed to register uploaded object key=712x15761s0ylp3nli5yd0vgfxqgvhj5.ls error="server returned 404: 404 page not found\n"15212026/10/06 21:13:03 WARN Failed to register uploaded object key=0d7hab4b100zhkldk2waqd0z9p9ah88c.ls error="server returned 404: 404 page not found\n"15222026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15232026/10/06 21:13:03 INFO Signed narinfos id=2 count=115242026/10/06 21:13:03 INFO Uploading 1 narinfos15252026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/2/complete15262026/10/06 21:13:03 WARN Failed to register uploaded object key=712x15761s0ylp3nli5yd0vgfxqgvhj5.narinfo error="server returned 404: 404 page not found\n"15272026/10/06 21:13:03 INFO Signed narinfos id=1 count=315282026/10/06 21:13:03 INFO Uploading 3 narinfos15292026/10/06 21:13:03 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=015302026/10/06 21:13:03 INFO Upload complete. (60ms)15312026/10/06 21:13:03 WARN Failed to register uploaded object key=0d7hab4b100zhkldk2waqd0z9p9ah88c.narinfo error="server returned 404: 404 page not found\n"15322026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete15332026/10/06 21:13:03 WARN Failed to register uploaded object key=ipa3fqsj4f91q9b3mayr3kxdx3p9xh38.narinfo error="server returned 404: 404 page not found\n"15342026/10/06 21:13:03 WARN Failed to register uploaded object key=i5vsv8636ll3affp6ay06ar84sapasaf.narinfo error="server returned 404: 404 page not found\n"15352026/10/06 21:13:03 INFO Vacuumed table table=pending_closures1536--- PASS: TestCacheStatsHandler (0.44s)1537=== CONT TestPendingClosureWriteTimeout/670k_objects1538=== CONT TestPendingClosureWriteTimeout/400_objects1539=== CONT TestProxyWriteTimeout/narinfo1540=== CONT TestProxyWriteTimeout/unknown_size1541=== CONT TestProxyWriteTimeout/10_GiB_nar1542=== CONT TestProxyWriteTimeout/1_GiB_nar15432026/10/06 21:13:03 INFO Received push request method=POST path=/api/pushes1544--- PASS: TestProxyWriteTimeout (0.08s)1545 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1546 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1547 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1548 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1549=== CONT TestIsValidUploadKey/narinfo1550=== CONT TestIsValidUploadKey/realisation_plus_in_output1551=== CONT TestIsValidUploadKey/unknown_type1552=== CONT TestIsValidUploadKey/empty_key15532026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete1554=== CONT TestIsValidUploadKey/absolute1555=== CONT TestIsValidUploadKey/traversal_nar1556=== CONT TestIsValidUploadKey/traversal1557=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1558=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1559=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1560=== CONT TestIsValidUploadKey/index.html1561=== CONT TestIsValidUploadKey/nix-cache-info1562=== CONT TestIsValidUploadKey/nar_plain1563=== CONT TestIsValidUploadKey/build_log1564=== CONT TestIsValidUploadKey/listing1565=== CONT TestIsValidUploadKey/build_log_equals1566=== CONT TestIsValidUploadKey/build_log_home-manager_file1567=== CONT TestIsValidUploadKey/realisation1568=== CONT TestIsValidUploadKey/build_log_question_mark1569=== CONT TestIsValidUploadKey/build_log_plus_in_name1570=== CONT TestIsValidUploadKey/nar_xz1571=== CONT TestIsValidUploadKey/nar_zst15722026/10/06 21:13:03 INFO Vacuumed table table=pending_objects1573=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15742026/10/06 21:13:03 INFO Received uploads request method=POST path=/1575--- PASS: TestIsValidUploadKey (0.08s)1576 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1577 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1578 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1579 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1580 --- PASS: TestIsValidUploadKey/absolute (0.00s)1581 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1582 --- PASS: TestIsValidUploadKey/traversal (0.00s)1583 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1584 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1585 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1586 --- PASS: TestIsValidUploadKey/index.html (0.00s)1587 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1588 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1589 --- PASS: TestIsValidUploadKey/build_log (0.00s)1590 --- PASS: TestIsValidUploadKey/listing (0.00s)1591 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1592 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1593 --- PASS: TestIsValidUploadKey/realisation (0.00s)1594 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1595 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1596 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1597 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)15982026/10/06 21:13:03 INFO Vacuumed table table=multipart_uploads15992026/10/06 21:13:03 INFO Upload complete. (89ms)1600=== NAME TestClientMultipleUploads1601 client_integration_test.go:369: Uploaded 3 paths in 124.165496ms16022026/10/06 21:13:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1603--- PASS: TestPush_CompleteCommitsEveryRoot (0.47s)16042026/10/06 21:13:03 INFO Uploading ipy0rp4yrp68p0w6k9spfh94xqd6gkyz-test-script (136B)1605=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16062026/10/06 21:13:03 INFO Received request for more parts method=POST path=/1607--- PASS: TestClientMultipleUploads (0.73s)1608=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16092026/10/06 21:13:03 INFO Received complete multipart upload request method=POST path=/16102026/10/06 21:13:03 INFO Vacuumed table table=closures16112026/10/06 21:13:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16122026/10/06 21:13:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46655/oidc16132026/10/06 21:13:03 WARN Failed to register uploaded object key=ipy0rp4yrp68p0w6k9spfh94xqd6gkyz.ls error="server returned 404: 404 page not found\n"16142026/10/06 21:13:03 INFO Vacuumed table table=objects16152026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/2/complete16162026/10/06 21:13:03 WARN Failed to register uploaded object key=log/2n3f42b2300d9isx8ll4qwm1imifi18x-test-script.drv error="server returned 404: 404 page not found\n"16172026/10/06 21:13:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16182026/10/06 21:13:03 INFO Signed narinfos id=1 count=116192026/10/06 21:13:03 INFO Uploading 1 narinfos1620--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.53s)1621=== CONT TestIsValidCachePath/narinfo1622=== CONT TestIsValidCachePath/index.html1623=== CONT TestIsValidCachePath/short_hash1624=== CONT TestIsValidCachePath/wrong_extension1625=== CONT TestIsValidCachePath/leading_slash1626=== CONT TestIsValidCachePath/invalid_char_e1627=== CONT TestIsValidCachePath/traversal_in_middle1628=== CONT TestIsValidCachePath/traversal_parent1629=== CONT TestIsValidCachePath/invalid_char_u1630=== CONT TestIsValidCachePath/empty1631=== CONT TestIsValidCachePath/random_path1632=== CONT TestIsValidCachePath/nar_uncompressed1633=== CONT TestIsValidCachePath/nix-cache-info1634=== CONT TestIsValidCachePath/nar_xz1635=== CONT TestIsValidCachePath/realisation1636=== CONT TestIsValidCachePath/nar_bz21637=== CONT TestIsValidCachePath/log1638=== CONT TestIsValidCachePath/ls1639=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1640=== CONT TestIsValidCachePath/nar_zst1641--- PASS: TestIsValidCachePath (0.00s)1642 --- PASS: TestIsValidCachePath/narinfo (0.00s)1643 --- PASS: TestIsValidCachePath/index.html (0.00s)1644 --- PASS: TestIsValidCachePath/short_hash (0.00s)1645 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1646 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1647 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1648 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1649 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1650 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1651 --- PASS: TestIsValidCachePath/empty (0.00s)1652 --- PASS: TestIsValidCachePath/random_path (0.00s)1653 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1654 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1655 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1656 --- PASS: TestIsValidCachePath/realisation (0.00s)1657 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1658 --- PASS: TestIsValidCachePath/log (0.00s)1659 --- PASS: TestIsValidCachePath/ls (0.00s)1660 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1661 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1662=== CONT TestParseSingleRange/none1663=== CONT TestParseSingleRange/open-ended1664=== CONT TestParseSingleRange/start_far_past_EOF1665=== CONT TestParseSingleRange/start_past_EOF1666=== CONT TestParseSingleRange/suffix1667=== CONT TestParseSingleRange/suffix_exceeds_size1668=== CONT TestParseSingleRange/single_byte1669=== CONT TestParseSingleRange/end_clamped_to_size1670=== CONT TestParseSingleRange/malformed_both_empty1671=== CONT TestParseSingleRange/closed1672=== CONT TestParseSingleRange/malformed_end_before_start1673=== CONT TestParseSingleRange/multi-range_ignored16742026/10/06 21:13:03 INFO Received complete push request method=POST path=/api/pushes/1/complete1675=== CONT TestParseSingleRange/malformed_no_dash1676=== CONT TestParseSingleRange/unknown_unit1677--- PASS: TestParseSingleRange (0.00s)1678 --- PASS: TestParseSingleRange/none (0.00s)1679 --- PASS: TestParseSingleRange/open-ended (0.00s)1680 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1681 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1682 --- PASS: TestParseSingleRange/suffix (0.00s)1683 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1684 --- PASS: TestParseSingleRange/single_byte (0.00s)1685 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1686 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1687 --- PASS: TestParseSingleRange/closed (0.00s)1688 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1689 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1690 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1691 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1692=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale16932026/10/06 21:13:03 WARN Failed to register uploaded object key=ipy0rp4yrp68p0w6k9spfh94xqd6gkyz.narinfo error="server returned 404: 404 page not found\n"16942026/10/06 21:13:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures16952026/10/06 21:13:03 INFO Garbage collection started16962026/10/06 21:13:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures16972026/10/06 21:13:03 INFO Garbage collection started16982026/10/06 21:13:03 INFO Upload complete. (112ms)1699=== NAME TestClientWithDependencies1700 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies640607193/001/store) requires matching store prefix1701--- PASS: TestClientWithDependencies (0.78s)1702=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh17032026/10/06 21:13:03 INFO Aborted multipart uploads count=0 kept=01704=== CONT TestServerTLSConfig/no_client_CA1705=== CONT TestServerTLSConfig/not_a_PEM_file1706=== CONT TestServerTLSConfig/missing_CA_file1707--- PASS: TestServerTLSConfig (0.00s)1708 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1709 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1710 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1711=== CONT TestGCEndsOnShutdown/before_the_run17122026/10/06 21:13:03 WARN Force mode enabled - objects will be deleted immediately without grace period17132026/10/06 21:13:03 INFO Aborted multipart uploads count=0 kept=017142026/10/06 21:13:03 WARN Force mode enabled - objects will be deleted immediately without grace period1715--- PASS: TestService_ReadAuthMiddleware (0.24s)1716=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17172026/10/06 21:13:03 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=017182026/10/06 21:13:03 INFO Vacuumed table table=pending_closures1719=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17202026/10/06 21:13:03 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=017212026/10/06 21:13:03 INFO Vacuumed table table=pending_objects17222026/10/06 21:13:03 INFO Vacuumed table table=multipart_uploads17232026/10/06 21:13:03 INFO Vacuumed table table=pending_closures17242026/10/06 21:13:03 INFO Vacuumed table table=closures17252026/10/06 21:13:03 INFO Vacuumed table table=pending_objects17262026/10/06 21:13:03 INFO Vacuumed table table=multipart_uploads17272026/10/06 21:13:03 INFO Vacuumed table table=objects17282026/10/06 21:13:03 INFO Vacuumed table table=closures17292026/10/06 21:13:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17302026/10/06 21:13:03 WARN mTLS auth: bound subjects configured but subject DN unavailable17312026/10/06 21:13:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1732--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.19s)1733=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17342026/10/06 21:13:03 INFO Vacuumed table table=objects1735=== NAME TestClientCADerivations1736 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations720719531/001/store/mnmkpacmrn6hvp63rvirc53k56vr8mr4-ca-test1737--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.20s)1738=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1739--- PASS: TestService_ReadScope_PublicByDefault (0.23s)1740=== CONT TestClientErrorHandling/InvalidStorePath1741=== NAME TestClientCADerivations1742 client_ca_test.go:139: Found 1 dependencies (including self)17432026/10/06 21:13:03 INFO Received uploads request method=POST path=/api/pending_closures1744=== RUN TestService_RequireScope_OIDC/builder_may_write1745=== PAUSE TestService_RequireScope_OIDC/builder_may_write1746=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1747=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1748=== RUN TestService_RequireScope_OIDC/ops_may_admin1749=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1750=== RUN TestService_RequireScope_OIDC/ops_may_not_write1751=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1752=== RUN TestService_RequireScope_OIDC/reader_may_not_write1753=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1754=== RUN TestService_RequireScope_OIDC/static_token_may_admin1755=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1756=== RUN TestService_RequireScope_OIDC/static_token_may_write1757=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1758=== RUN TestService_RequireScope_OIDC/reader_may_read1759=== PAUSE TestService_RequireScope_OIDC/reader_may_read1760=== RUN TestService_RequireScope_OIDC/writer_implies_read1761=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1762=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1763=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1764=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1765=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1766=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1767=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1768=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1769=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1770=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1771=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1772=== CONT TestClientErrorHandling/ServerNotAvailable1773=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1774=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1775=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1776=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1777=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1778=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1779=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1780=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1781=== CONT TestClientErrorHandling/InvalidAuthToken17822026/10/06 21:13:04 INFO lead: released remote=192.0.2.1:12341783--- PASS: TestLeadEndsOnShutdown (1.62s)1784=== CONT TestResolveDBConnectionString/flag_wins1785=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1786=== CONT TestResolveDBConnectionString/nothing_configured1787=== CONT TestResolveDBConnectionString/missing_file_is_an_error1788=== CONT TestResolveDBConnectionString/file_when_flag_empty1789=== CONT TestCacheConfigHandler/full_config,_no_issuer1790=== CONT TestCacheConfigHandler/no_signing_keys1791--- PASS: TestResolveDBConnectionString (0.00s)1792 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1793 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1794 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1795 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1796 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1797=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1798=== CONT TestCacheConfigHandler/no_cache_url_configured1799=== CONT TestPush_RejectsBadRequests/no_roots1800--- PASS: TestCacheConfigHandler (0.00s)1801 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1802 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1803 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1804 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)18052026/10/06 21:13:04 INFO Received push request method=POST path=/api/pushes1806=== CONT TestPush_RejectsBadRequests/bad_root18072026/10/06 21:13:04 INFO Received push request method=POST path=/api/pushes1808=== CONT TestPush_RejectsBadRequests/root_not_in_objects18092026/10/06 21:13:04 INFO Received push request method=POST path=/api/pushes1810=== CONT TestPush_RejectsBadRequests/no_objects18112026/10/06 21:13:04 INFO Received push request method=POST path=/api/pushes1812=== CONT TestService_RequireScope_OIDC/builder_may_write1813--- PASS: TestPush_RejectsBadRequests (0.39s)1814 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1815 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1816 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1817 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1818=== CONT TestService_RequireScope_OIDC/reader_may_read1819=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1820=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18212026/10/06 21:13:04 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]1822=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1823=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1824=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1825=== CONT TestService_RequireScope_OIDC/writer_implies_read1826=== CONT TestService_RequireScope_OIDC/ops_may_admin1827=== CONT TestService_RequireScope_OIDC/reader_may_not_write1828=== CONT TestService_RequireScope_OIDC/static_token_may_write1829=== CONT TestService_RequireScope_OIDC/ops_may_not_write1830=== CONT TestService_RequireScope_OIDC/static_token_may_admin1831=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1832=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1833--- PASS: TestService_RequireScope_OIDC (0.26s)1834 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1842 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1843 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1844 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1845 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1846 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1847 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18482026/10/06 21:13:04 INFO Received push request method=POST path=/api/pushes1849=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1850=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18512026/10/06 21:13:04 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]1852=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18532026/10/06 21:13:04 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/present18542026/10/06 21:13:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18552026/10/06 21:13:04 INFO Uploading mnmkpacmrn6hvp63rvirc53k56vr8mr4-ca-test (144B)18562026/10/06 21:13:04 WARN Authentication failed token_preview=eyJhbGciOi...sXIYekB78g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1857--- PASS: TestService_AuthMiddleware_OIDC (0.34s)1858 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1859 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1860 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1861 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18622026/10/06 21:13:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18632026/10/06 21:13:04 WARN Failed to register uploaded object key=log/3df1sn2a30bb7kvb5yjskfhjncq4blhr-ca-test.drv error="server returned 404: 404 page not found\n"18642026/10/06 21:13:04 WARN Failed to register uploaded object key=mnmkpacmrn6hvp63rvirc53k56vr8mr4.ls error="server returned 404: 404 page not found\n"18652026/10/06 21:13:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18662026/10/06 21:13:04 INFO Signed narinfos id=1 count=118672026/10/06 21:13:04 INFO Uploading 1 narinfos18682026/10/06 21:13:04 INFO Received complete push request method=POST path=/api/pushes/1/complete18692026/10/06 21:13:04 INFO Upload complete. (409ms)18702026/10/06 21:13:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1871=== NAME TestOrphanedObjectsGCStressTest1872 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1873--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1874 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1875 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1876 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.70s)18772026/10/06 21:13:04 WARN Failed to register uploaded object key=mnmkpacmrn6hvp63rvirc53k56vr8mr4.narinfo error="server returned 404: 404 page not found\n"18782026/10/06 21:13:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.569381ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1879=== NAME TestClientCADerivations1880 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations720719531/001/store/mnmkpacmrn6hvp63rvirc53k56vr8mr4-ca-test1881 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1882 Compression: zstd1883 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1884 NarSize: 1441885 References: 1886 Deriver: /build/TestClientCADerivations720719531/001/store/3df1sn2a30bb7kvb5yjskfhjncq4blhr-ca-test.drv1887 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1888 client_ca_test.go:185: Checking for realisation files in S3...1889 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1890 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18912026/10/06 21:13:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18922026/10/06 21:13:04 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLmQwMzlmN2YzLTBmNzktNGUzNS1iNjg5LWY4ZmRmYzU5NmFlYXgxNzkxMzIxMTgzNDE5MTY1NjU2 parts=121893=== NAME TestOrphanedObjectsGCStressTest1894 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18952026/10/06 21:13:04 INFO Received uploads request method=POST path=/api/pending_closures1896--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.33s)18972026/10/06 21:13:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLjZhY2M2MTgzLThiNDMtNDczYy05MGQ5LTJlNTE1ZmIyMjIzMXgxNzkxMzIxMTgzNDkyOTk2NzQ4 parts=1218982026/10/06 21:13:04 INFO Received uploads request method=POST path=/api/pending_closures18992026/10/06 21:13:04 INFO Received uploads request method=POST path=/api/pending_closures19002026/10/06 21:13:04 INFO Aborted multipart uploads count=0 kept=019012026/10/06 21:13:04 WARN Force mode enabled - objects will be deleted immediately without grace period19022026-10-06 21:13:04.366 UTC [1837] ERROR: canceling statement due to user request19032026-10-06 21:13:04.366 UTC [1837] CONTEXT: SQL statement "UPDATE object_stats1904 SET object_count = object_count + d_count,1905 total_bytes = total_bytes + d_bytes1906 WHERE id"1907 PL/pgSQL function object_stats_apply() line 17 at SQL statement19082026-10-06 21:13:04.366 UTC [1837] STATEMENT: -- name: MarkStaleObjects :execrows1909 WITH RECURSIVE ct AS (1910 SELECT timezone('UTC', now()) AS now1911 ),1912 closure_reach AS (1913 -- Start with all closure keys1914 SELECT o.key, o.refs1915 FROM objects o1916 INNER JOIN closures c ON o.key = c.key1917 UNION1918 -- Recursively add all referenced objects1919 SELECT o.key, o.refs1920 FROM objects o1921 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1922 ),1923 reachable_objects AS (1924 SELECT DISTINCT key FROM closure_reach1925 ),1926 stale_objects AS (1927 SELECT o.key1928 FROM objects AS o, ct1929 WHERE1930 NOT EXISTS (1931 SELECT 11932 FROM reachable_objects ro1933 WHERE ro.key = o.key1934 )1935 AND NOT EXISTS (1936 SELECT 11937 FROM pending_objects AS po1938 WHERE po.key = o.key1939 )1940 AND o.deleted_at IS NULL -- Only mark fresh objects1941 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1942 FOR UPDATE1943 )1944 UPDATE objects1945 SET1946 deleted_at = ct.now,1947 first_deleted_at = COALESCE(first_deleted_at, ct.now)1948 FROM stale_objects, ct1949 WHERE objects.key = stale_objects.key1950 19512026/10/06 21:13:04 INFO Aborted multipart uploads count=0 kept=019522026/10/06 21:13:04 WARN Force mode enabled - objects will be deleted immediately without grace period19532026/10/06 21:13:04 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40307/bucket90/?delete=\": context canceled"1954--- PASS: TestGCEndsOnShutdown (0.00s)1955 --- PASS: TestGCEndsOnShutdown/before_the_run (0.68s)1956 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.72s)1957 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.72s)19582026/10/06 21:13:04 INFO Received uploads request method=POST path=/api/pending_closures19592026/10/06 21:13:04 INFO Aborted multipart uploads count=0 kept=019602026/10/06 21:13:04 WARN Force mode enabled - objects will be deleted immediately without grace period19612026/10/06 21:13:04 INFO Received uploads request method=POST path=/api/pending_closures19622026/10/06 21:13:04 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=019632026/10/06 21:13:04 INFO Vacuumed table table=pending_closures19642026/10/06 21:13:04 INFO Vacuumed table table=pending_objects19652026/10/06 21:13:04 INFO Vacuumed table table=multipart_uploads19662026/10/06 21:13:04 INFO Vacuumed table table=closures19672026/10/06 21:13:04 INFO Vacuumed table table=objects1968=== NAME TestClientCADerivations1969 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1970 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1971 error: binary cache 's3://bucket77?endpoint=http://localhost:40307®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations720719531/001/store'1972 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119732026/10/06 21:13:04 INFO Aborted multipart uploads count=0 kept=019742026/10/06 21:13:04 INFO lead: released remote=192.0.2.1:123419752026/10/06 21:13:04 WARN Force mode enabled - objects will be deleted immediately without grace period1976--- PASS: TestClientCADerivations (1.14s)19772026/10/06 21:13:04 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=019782026/10/06 21:13:04 INFO Vacuumed table table=pending_closures19792026/10/06 21:13:04 INFO Vacuumed table table=pending_objects19802026/10/06 21:13:04 INFO Vacuumed table table=multipart_uploads19812026/10/06 21:13:04 INFO Vacuumed table table=closures19822026/10/06 21:13:04 INFO Vacuumed table table=objects1983--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1984 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.75s)1985 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.74s)19862026/10/06 21:13:04 INFO lead: acquired remote=192.0.2.1:123419872026/10/06 21:13:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.250982ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19882026/10/06 21:13:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1989--- PASS: TestPendingClosureWriteTimeout (0.08s)1990 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1991 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1992 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1993 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)19942026/10/06 21:13:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1995=== NAME TestOrphanedObjectsGCStressTest1996 orphaned_objects_gc_test.go:509: Stress test completed successfully:1997 orphaned_objects_gc_test.go:510: - Active objects preserved: 201998 orphaned_objects_gc_test.go:511: - Objects deleted: 2101999 orphaned_objects_gc_test.go:512: - Total GC'd: 2102000--- PASS: TestOrphanedObjectsGCStressTest (3.05s)2001--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2002 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.06s)2003 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.06s)20042026/10/06 21:13:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20052026/10/06 21:13:04 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLjVkZThhM2Q2LTM5MDUtNGI5NC04MzAyLWMzMTQ5MWNhYTRmYXgxNzkxMzIxMTg0MzE0NjMzNzg0 error="Get \"http://127.0.0.1:1/bucket73/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20062026/10/06 21:13:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTE2NTUyNjEtZjEwNC00NTdlLWFlMTYtNzZmYzBiZDY4NjFiLjQyNmMyMjNkLTc1OGMtNGUxOS1hMmEyLTE4MTY0OWM5ODkwM3gxNzkxMzIxMTg0MzA5MzU5OTc5 parts=1220072026/10/06 21:13:04 INFO Received cleanup request method=DELETE path=/api/pending_closures20082026/10/06 21:13:04 INFO Aborted multipart uploads count=1 kept=02009--- PASS: TestRedundantMultipartUpload (1.77s)20102026/10/06 21:13:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=749.092445ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20112026/10/06 21:13:05 INFO lead: released remote=192.0.2.1:12342012--- PASS: TestLeadElectsOneAndHandsOver (2.96s)20132026/10/06 21:13:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.552053797s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20142026/10/06 21:13:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020152026/10/06 21:13:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02016=== NAME TestClientIntegration2017 client_integration_test.go:323: Objects in database after GC:2018 client_integration_test.go:323: Successfully deleted all objects with GC --force20192026/10/06 21:13:05 INFO Received create pin request method=POST path=/api/pins/myapp2020--- PASS: TestClientIntegration (2.76s)20212026/10/06 21:13:05 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2530032632/001/store/7w1b1ppdm6dkx8vywy06wwdc9rwgxh44-pinned-file.txt narinfo_key=7w1b1ppdm6dkx8vywy06wwdc9rwgxh44.narinfo20222026/10/06 21:13:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures20232026/10/06 21:13:05 INFO Garbage collection started20242026/10/06 21:13:05 INFO Aborted multipart uploads count=0 kept=020252026/10/06 21:13:05 WARN Force mode enabled - objects will be deleted immediately without grace period20262026/10/06 21:13:05 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=020272026/10/06 21:13:05 INFO Vacuumed table table=pending_closures20282026/10/06 21:13:05 INFO Vacuumed table table=pending_objects20292026/10/06 21:13:05 INFO Vacuumed table table=multipart_uploads20302026/10/06 21:13:05 INFO Vacuumed table table=closures20312026/10/06 21:13:05 INFO Vacuumed table table=objects20322026/10/06 21:13:06 WARN Rate limiter enabled after throttle name=s3-test rate=520332026/10/06 21:13:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2034=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2035 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102036 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002037--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.32s)20382026/10/06 21:13:07 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-config2039--- PASS: TestConnectWaitsForAPeerMigration (5.17s)20402026/10/06 21:13:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.495739ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/06 21:13:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.369679ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2042=== NAME TestPinProtectsFromGC2043 client_integration_test.go:840: Pin successfully protected closure from garbage collection2044--- PASS: TestPinProtectsFromGC (4.90s)20452026/10/06 21:13:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.587397ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2046--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.45s)20472026/10/06 21:13:08 INFO Aborted multipart uploads count=1 kept=020482026/10/06 21:13:08 INFO Received cleanup request method=DELETE path=/api/pending_closures20492026/10/06 21:13:08 INFO Aborted multipart uploads count=1 kept=02050--- PASS: TestPendingCleanupUsesOneCutoff (6.67s)20512026/10/06 21:13:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.684704296s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20522026/10/06 21:13:10 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"20532026/10/06 21:13:10 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-config20542026/10/06 21:13:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.476416ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20552026/10/06 21:13:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.027102ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20562026/10/06 21:13:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=859.978949ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20572026/10/06 21:13:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.618054039s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20582026/10/06 21:13:13 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_closures20592026/10/06 21:13:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.692401ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20602026/10/06 21:13:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.175953ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20612026/10/06 21:13:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.918622ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20622026/10/06 21:13:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.740374609s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2063--- PASS: TestClientErrorHandling (0.00s)2064 --- PASS: TestClientErrorHandling/InvalidStorePath (0.73s)2065 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.77s)2066 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.91s)2067PASS20682026-10-06 21:13:17.119 UTC [132] LOG: received smart shutdown request20692026-10-06 21:13:17.123 UTC [132] LOG: background worker "logical replication launcher" (PID 142) exited with exit code 120702026-10-06 21:13:17.134 UTC [137] LOG: shutting down20712026-10-06 21:13:17.135 UTC [137] LOG: checkpoint starting: shutdown immediate20722026-10-06 21:13:18.745 UTC [137] LOG: checkpoint complete: wrote 11165 buffers (68.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.663 s, sync=0.886 s, total=1.611 s; sync files=32008, longest=0.017 s, average=0.001 s; distance=442177 kB, estimate=442177 kB; lsn=0/1C7362F8, redo lsn=0/1C7362F820732026-10-06 21:13:18.827 UTC [132] LOG: database system is shut down2074Running OIDC tests...2075=== RUN TestAudienceForIssuer2076=== PAUSE TestAudienceForIssuer2077=== RUN TestGlobMatch2078=== PAUSE TestGlobMatch2079=== RUN TestValidateToken_ValidToken2080=== PAUSE TestValidateToken_ValidToken2081=== RUN TestValidateToken_WrongAudience2082=== PAUSE TestValidateToken_WrongAudience2083=== RUN TestValidateToken_Expired2084=== PAUSE TestValidateToken_Expired2085=== RUN TestValidateToken_BoundClaimsMismatch2086=== PAUSE TestValidateToken_BoundClaimsMismatch2087=== RUN TestValidateToken_BoundSubjectMismatch2088=== PAUSE TestValidateToken_BoundSubjectMismatch2089=== RUN TestValidateToken_MultipleProviders2090=== PAUSE TestValidateToken_MultipleProviders2091=== RUN TestValidateToken_NoMatchingProvider2092=== PAUSE TestValidateToken_NoMatchingProvider2093=== RUN TestValidateToken_KubernetesServiceAccount2094=== PAUSE TestValidateToken_KubernetesServiceAccount2095=== RUN TestNewValidator_KubernetesRequiresCA2096=== PAUSE TestNewValidator_KubernetesRequiresCA2097=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2098=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2099=== RUN TestPins_ReservedForMatchingRule2100=== PAUSE TestPins_ReservedForMatchingRule2101=== RUN TestPins_TopLevelShorthand2102=== PAUSE TestPins_TopLevelShorthand2103=== RUN TestPins_ConfigValidation2104=== PAUSE TestPins_ConfigValidation2105=== RUN TestScopes_LegacyProviderDefaultsToWrite2106=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2107=== RUN TestScopes_Rules2108=== PAUSE TestScopes_Rules2109=== RUN TestScopes_ConfigValidation2110=== PAUSE TestScopes_ConfigValidation2111=== CONT TestAudienceForIssuer2112=== CONT TestValidateToken_KubernetesServiceAccount2113=== CONT TestPins_ReservedForMatchingRule2114=== CONT TestPins_ConfigValidation2115=== CONT TestScopes_ConfigValidation2116=== CONT TestScopes_Rules2117=== CONT TestScopes_LegacyProviderDefaultsToWrite2118=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2119=== CONT TestPins_TopLevelShorthand2120=== CONT TestNewValidator_KubernetesRequiresCA2121=== CONT TestValidateToken_BoundClaimsMismatch2122=== CONT TestValidateToken_NoMatchingProvider2123=== CONT TestValidateToken_MultipleProviders2124=== CONT TestValidateToken_BoundSubjectMismatch2125=== CONT TestValidateToken_WrongAudience2126=== CONT TestValidateToken_Expired2127=== CONT TestValidateToken_ValidToken2128=== CONT TestGlobMatch2129=== RUN TestGlobMatch/foo_foo2130=== PAUSE TestGlobMatch/foo_foo2131--- PASS: TestAudienceForIssuer (0.00s)2132=== RUN TestGlobMatch/foo_bar2133=== PAUSE TestGlobMatch/foo_bar2134--- PASS: TestPins_ConfigValidation (0.00s)2135--- PASS: TestScopes_ConfigValidation (0.00s)2136=== RUN TestGlobMatch/*_2137=== PAUSE TestGlobMatch/*_2138=== RUN TestGlobMatch/*_anything2139=== PAUSE TestGlobMatch/*_anything2140=== RUN TestGlobMatch/foo*_foo2141=== PAUSE TestGlobMatch/foo*_foo2142=== RUN TestGlobMatch/foo*_foobar2143=== PAUSE TestGlobMatch/foo*_foobar2144=== RUN TestGlobMatch/foo*_bar2145=== PAUSE TestGlobMatch/foo*_bar2146=== RUN TestGlobMatch/*bar_bar2147=== PAUSE TestGlobMatch/*bar_bar2148=== RUN TestGlobMatch/*bar_foobar2149=== PAUSE TestGlobMatch/*bar_foobar2150=== RUN TestGlobMatch/*bar_foo2151=== PAUSE TestGlobMatch/*bar_foo2152=== RUN TestGlobMatch/foo*bar_foobar2153=== PAUSE TestGlobMatch/foo*bar_foobar2154=== RUN TestGlobMatch/foo*bar_foo123bar2155=== PAUSE TestGlobMatch/foo*bar_foo123bar2156=== RUN TestGlobMatch/foo*bar_foobarbaz2157=== PAUSE TestGlobMatch/foo*bar_foobarbaz2158=== RUN TestGlobMatch/*/*_foo/bar2159=== PAUSE TestGlobMatch/*/*_foo/bar2160=== RUN TestGlobMatch/*/*_foo2161=== PAUSE TestGlobMatch/*/*_foo2162=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2163=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2164=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02165=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02166=== RUN TestGlobMatch/refs/*/main_refs/heads/main2167=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2168=== RUN TestGlobMatch/fo?_foo2169=== PAUSE TestGlobMatch/fo?_foo2170=== RUN TestGlobMatch/fo?_fo2171=== PAUSE TestGlobMatch/fo?_fo2172=== RUN TestGlobMatch/fo?_fooo2173=== PAUSE TestGlobMatch/fo?_fooo2174=== RUN TestGlobMatch/?oo_foo2175=== PAUSE TestGlobMatch/?oo_foo2176=== RUN TestGlobMatch/?oo_boo2177=== PAUSE TestGlobMatch/?oo_boo2178=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2179=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2180=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2181=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2182=== CONT TestGlobMatch/foo_foo2183=== CONT TestGlobMatch/*bar_bar2184=== CONT TestGlobMatch/fo?_fo2185=== CONT TestGlobMatch/fo?_foo2186=== CONT TestGlobMatch/refs/*/main_refs/heads/main2187=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2188=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02189=== CONT TestGlobMatch/foo*_foo2190=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2191=== CONT TestGlobMatch/*_anything2192=== CONT TestGlobMatch/*/*_foo2193=== CONT TestGlobMatch/*_2194=== CONT TestGlobMatch/*/*_foo/bar2195=== CONT TestGlobMatch/foo_bar2196=== CONT TestGlobMatch/foo*_bar2197=== CONT TestGlobMatch/*bar_foobar2198=== CONT TestGlobMatch/foo*bar_foobarbaz2199=== CONT TestGlobMatch/foo*bar_foo123bar2200=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2201=== CONT TestGlobMatch/foo*bar_foobar2202=== CONT TestGlobMatch/?oo_boo2203=== CONT TestGlobMatch/?oo_foo2204=== CONT TestGlobMatch/fo?_fooo2205=== CONT TestGlobMatch/foo*_foobar2206=== CONT TestGlobMatch/*bar_foo2207--- PASS: TestGlobMatch (0.00s)2208 --- PASS: TestGlobMatch/foo_foo (0.00s)2209 --- PASS: TestGlobMatch/*bar_bar (0.00s)2210 --- PASS: TestGlobMatch/fo?_fo (0.00s)2211 --- PASS: TestGlobMatch/fo?_foo (0.00s)2212 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2213 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2214 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2215 --- PASS: TestGlobMatch/foo*_foo (0.00s)2216 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2217 --- PASS: TestGlobMatch/*_anything (0.00s)2218 --- PASS: TestGlobMatch/*/*_foo (0.00s)2219 --- PASS: TestGlobMatch/*_ (0.00s)2220 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2221 --- PASS: TestGlobMatch/foo_bar (0.00s)2222 --- PASS: TestGlobMatch/foo*_bar (0.00s)2223 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2224 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2225 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2226 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2227 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2228 --- PASS: TestGlobMatch/?oo_boo (0.00s)2229 --- PASS: TestGlobMatch/?oo_foo (0.00s)2230 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2231 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2232 --- PASS: TestGlobMatch/*bar_foo (0.00s)22332026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42293/oidc22342026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33045/oidc2235--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)2236--- PASS: TestScopes_Rules (0.04s)22372026/10/06 21:13:21 http: TLS handshake error from 127.0.0.1:53720: remote error: tls: bad certificate2238--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)22392026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35685/oidc2240--- PASS: TestPins_ReservedForMatchingRule (0.07s)22412026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40547/oidc2242--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)22432026/10/06 21:13:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34995/oidc22442026/10/06 21:13:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:458252245--- PASS: TestValidateToken_NoMatchingProvider (0.10s)22462026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34941/oidc2247--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)2248--- PASS: TestPins_TopLevelShorthand (0.11s)22492026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40391/oidc22502026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41457/oidc2251--- PASS: TestValidateToken_ValidToken (0.11s)2252--- PASS: TestValidateToken_WrongAudience (0.11s)22532026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34565/oidc2254--- PASS: TestValidateToken_BoundSubjectMismatch (0.14s)22552026/10/06 21:13:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35709/oidc22562026/10/06 21:13:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37969/oidc2257--- PASS: TestValidateToken_MultipleProviders (0.15s)22582026/10/06 21:13:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322592026/10/06 21:13:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38011/oidc2260--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)2261--- PASS: TestValidateToken_Expired (0.16s)2262PASS2263Running hook tests...2264=== RUN TestSendPathsEmpty2265=== PAUSE TestSendPathsEmpty2266=== RUN TestQueueEnqueueAndFetch2267=== PAUSE TestQueueEnqueueAndFetch2268=== RUN TestQueueDeduplication2269=== PAUSE TestQueueDeduplication2270=== RUN TestQueueRemove2271=== PAUSE TestQueueRemove2272=== RUN TestQueueFetchBatchLimit2273=== PAUSE TestQueueFetchBatchLimit2274=== RUN TestQueueRetryMovesToBack2275=== PAUSE TestQueueRetryMovesToBack2276=== RUN TestQueueFetchRemoveLifecycle2277=== PAUSE TestQueueFetchRemoveLifecycle2278=== RUN TestQueueConcurrentWriters2279=== PAUSE TestQueueConcurrentWriters2280=== RUN TestQueueRemoveLargeClosure2281=== PAUSE TestQueueRemoveLargeClosure2282=== RUN TestServerClientIntegration2283=== PAUSE TestServerClientIntegration2284=== RUN TestServerQueueError2285=== PAUSE TestServerQueueError2286=== RUN TestGetListenerSocketActivation2287 server_test.go:210: === RUN TestGetListenerSocketActivation2288 --- PASS: TestGetListenerSocketActivation (0.00s)2289 PASS2290 2291--- PASS: TestGetListenerSocketActivation (0.02s)2292=== RUN TestDrainIsolatesPoisonPath2293=== PAUSE TestDrainIsolatesPoisonPath2294=== RUN TestRunNotBlockedByPoisonHead2295=== PAUSE TestRunNotBlockedByPoisonHead2296=== RUN TestDrainGivesUpWhenServerDown2297=== PAUSE TestDrainGivesUpWhenServerDown2298=== RUN TestFailedPathPrunedByLaterClosure2299=== PAUSE TestFailedPathPrunedByLaterClosure2300=== RUN TestWorkerUploadsAndRemoves2301=== PAUSE TestWorkerUploadsAndRemoves2302=== RUN TestWorkerSkipsGCdPaths2303=== PAUSE TestWorkerSkipsGCdPaths2304=== RUN TestWorkerPrunesClosureDeps2305=== PAUSE TestWorkerPrunesClosureDeps2306=== RUN TestDrainTimeout2307=== PAUSE TestDrainTimeout2308=== CONT TestSendPathsEmpty2309=== CONT TestQueueEnqueueAndFetch2310=== CONT TestServerQueueError2311=== CONT TestDrainTimeout2312=== CONT TestWorkerPrunesClosureDeps2313=== CONT TestWorkerSkipsGCdPaths2314=== CONT TestWorkerUploadsAndRemoves2315=== CONT TestFailedPathPrunedByLaterClosure2316=== CONT TestDrainGivesUpWhenServerDown2317=== CONT TestRunNotBlockedByPoisonHead2318=== CONT TestQueueRetryMovesToBack2319=== CONT TestServerClientIntegration23202026/10/06 21:13:21 ERROR Failed to queue paths error="permission denied" count=12321=== CONT TestQueueRemoveLargeClosure2322=== CONT TestDrainIsolatesPoisonPath2323=== CONT TestQueueConcurrentWriters2324=== CONT TestQueueRemove2325=== CONT TestQueueFetchRemoveLifecycle2326=== CONT TestQueueFetchBatchLimit2327=== CONT TestQueueDeduplication2328--- PASS: TestSendPathsEmpty (0.00s)2329--- PASS: TestServerQueueError (0.00s)2330--- PASS: TestServerClientIntegration (0.00s)23312026/10/06 21:13:21 INFO Upload queue status pending=223322026/10/06 21:13:21 INFO Uploading batch count=223332026/10/06 21:13:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths56259598/002/nonexistent23342026/10/06 21:13:21 INFO Upload queue status pending=223352026/10/06 21:13:21 INFO Uploading batch count=223362026/10/06 21:13:21 INFO Uploading batch count=12337--- PASS: TestQueueFetchBatchLimit (0.01s)23382026/10/06 21:13:21 INFO Uploading batch count=123392026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=12340--- PASS: TestQueueEnqueueAndFetch (0.02s)23412026/10/06 21:13:21 INFO Uploading batch count=423422026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=42343--- PASS: TestQueueDeduplication (0.02s)23442026/10/06 21:13:21 INFO Upload queue status pending=323452026/10/06 21:13:21 INFO Upload queue status pending=223462026/10/06 21:13:21 INFO Uploading batch count=223472026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=223482026/10/06 21:13:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1803415101/002/a2349--- PASS: TestQueueRetryMovesToBack (0.02s)23502026/10/06 21:13:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath569045767/002/bbb23512026/10/06 21:13:21 INFO Uploading batch count=123522026/10/06 21:13:21 INFO Uploading batch count=123532026/10/06 21:13:21 INFO Uploading batch count=123542026/10/06 21:13:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1803415101/002/b2355--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23562026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=12357--- PASS: TestQueueRemove (0.02s)23582026/10/06 21:13:21 INFO Uploading batch count=123592026/10/06 21:13:21 INFO Uploading batch count=223602026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=223612026/10/06 21:13:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1803415101/002/c23622026/10/06 21:13:21 INFO Uploading batch count=123632026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=123642026/10/06 21:13:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1803415101/002/d23652026/10/06 21:13:21 INFO Uploading batch count=123662026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=123672026/10/06 21:13:21 INFO Uploading batch count=223682026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=223692026/10/06 21:13:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1803415101/002/e23702026/10/06 21:13:21 INFO Uploading batch count=123712026/10/06 21:13:21 ERROR Upload failed error="upload failed" count=123722026/10/06 21:13:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1803415101/002/f2373--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)23742026/10/06 21:13:21 ERROR Drain finished with paths left in queue remaining=123752026/10/06 21:13:21 ERROR Drain finished with paths left in queue remaining=102376--- PASS: TestDrainIsolatesPoisonPath (0.03s)2377--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2378--- PASS: TestWorkerSkipsGCdPaths (0.04s)2379--- PASS: TestWorkerUploadsAndRemoves (0.04s)2380--- PASS: TestWorkerPrunesClosureDeps (0.04s)2381--- PASS: TestQueueRemoveLargeClosure (0.06s)23822026/10/06 21:13:22 ERROR Upload failed error="context deadline exceeded" count=223832026/10/06 21:13:22 ERROR Drain finished with paths left in queue remaining=42384--- PASS: TestDrainTimeout (0.22s)2385--- PASS: TestQueueConcurrentWriters (0.28s)23862026/10/06 21:13:22 INFO Uploading batch count=123872026/10/06 21:13:22 INFO Uploading batch count=123882026/10/06 21:13:22 INFO Uploading batch count=123892026/10/06 21:13:22 ERROR Upload failed error="upload failed" count=123902026/10/06 21:13:22 INFO Uploading batch count=123912026/10/06 21:13:22 ERROR Upload failed error="upload failed" count=123922026/10/06 21:13:22 INFO Uploading batch count=123932026/10/06 21:13:22 ERROR Upload failed error="upload failed" count=123942026/10/06 21:13:22 INFO Uploading batch count=123952026/10/06 21:13:22 ERROR Upload failed error="upload failed" count=123962026/10/06 21:13:22 ERROR Drain finished with paths left in queue remaining=12397--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2398PASS2399Running signing tests...2400=== RUN TestExternalSigner2401=== PAUSE TestExternalSigner2402=== RUN TestExternalSignerWrongPublicKey2403=== PAUSE TestExternalSignerWrongPublicKey2404=== RUN TestExternalSignerErrors2405=== PAUSE TestExternalSignerErrors2406=== RUN TestExternalSignerRestartsAfterCrash2407=== PAUSE TestExternalSignerRestartsAfterCrash2408=== RUN TestExternalSignerProgramErrorKeepsProcess2409=== PAUSE TestExternalSignerProgramErrorKeepsProcess2410=== RUN TestExternalSignerClose2411=== PAUSE TestExternalSignerClose2412=== RUN TestExternalSignerRejectsInvalidPublicKey2413=== PAUSE TestExternalSignerRejectsInvalidPublicKey2414=== RUN TestExternalSignerCancellation2415=== PAUSE TestExternalSignerCancellation2416=== RUN TestGenerateFingerprint2417=== PAUSE TestGenerateFingerprint2418=== RUN TestParseSigningKey2419=== PAUSE TestParseSigningKey2420=== RUN TestSign2421=== PAUSE TestSign2422=== RUN TestSignBatch2423=== PAUSE TestSignBatch2424=== RUN TestNilKeyPublicKey2425=== PAUSE TestNilKeyPublicKey2426=== RUN TestSignErrors2427=== PAUSE TestSignErrors2428=== CONT TestExternalSigner2429=== CONT TestExternalSignerCancellation2430=== CONT TestExternalSignerRejectsInvalidPublicKey2431=== CONT TestExternalSignerProgramErrorKeepsProcess2432=== CONT TestExternalSignerClose2433=== CONT TestSign2434=== CONT TestNilKeyPublicKey2435=== CONT TestSignBatch2436=== CONT TestParseSigningKey2437=== CONT TestSignErrors2438=== CONT TestExternalSignerErrors2439=== CONT TestExternalSignerRestartsAfterCrash2440=== CONT TestGenerateFingerprint2441=== CONT TestExternalSignerWrongPublicKey2442=== RUN TestExternalSignerRejectsInvalidPublicKey/#002443--- PASS: TestNilKeyPublicKey (0.00s)2444=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002445=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2446=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2447=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2448=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2449=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2450=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2451=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2452=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2453=== CONT TestExternalSignerRejectsInvalidPublicKey/#002454=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2455=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2456=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2457=== RUN TestExternalSignerErrors/null2458=== PAUSE TestExternalSignerErrors/null2459=== RUN TestGenerateFingerprint/basic_with_references2460=== RUN TestParseSigningKey/valid_32-byte_key2461=== PAUSE TestParseSigningKey/valid_32-byte_key2462=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2463--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2464 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2465 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2466 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2467 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2468 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2469=== RUN TestExternalSignerErrors/wrong_signature_length2470=== PAUSE TestExternalSignerErrors/wrong_signature_length2471=== PAUSE TestGenerateFingerprint/basic_with_references2472--- PASS: TestSign (0.00s)2473=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2474=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2475=== RUN TestExternalSignerErrors/program_error2476=== PAUSE TestExternalSignerErrors/program_error2477=== RUN TestGenerateFingerprint/no_references2478=== PAUSE TestGenerateFingerprint/no_references2479=== RUN TestSignErrors/nil_key2480=== RUN TestParseSigningKey/no_colon2481=== PAUSE TestParseSigningKey/no_colon2482--- PASS: TestSignBatch (0.00s)2483=== RUN TestExternalSignerErrors/exit_on_request2484=== PAUSE TestExternalSignerErrors/exit_on_request2485=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2486=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2487=== PAUSE TestSignErrors/nil_key2488=== RUN TestParseSigningKey/empty_name2489=== PAUSE TestParseSigningKey/empty_name2490=== RUN TestParseSigningKey/invalid_base642491=== PAUSE TestParseSigningKey/invalid_base642492=== RUN TestParseSigningKey/wrong_length2493=== PAUSE TestParseSigningKey/wrong_length2494=== CONT TestParseSigningKey/valid_32-byte_key2495=== CONT TestParseSigningKey/invalid_base642496=== RUN TestExternalSignerErrors/wrong_id2497=== PAUSE TestExternalSignerErrors/wrong_id2498=== RUN TestExternalSignerErrors/null_signatures2499=== PAUSE TestExternalSignerErrors/null_signatures2500=== RUN TestExternalSignerErrors/too_few_signatures2501=== PAUSE TestExternalSignerErrors/too_few_signatures2502=== RUN TestExternalSignerErrors/unrequested_key2503=== PAUSE TestExternalSignerErrors/unrequested_key2504=== RUN TestExternalSignerErrors/missing_signature_name2505=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2506=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2507=== RUN TestSignErrors/nil_narinfo2508=== PAUSE TestSignErrors/nil_narinfo2509=== RUN TestSignErrors/invalid_narinfo2510=== PAUSE TestSignErrors/invalid_narinfo2511=== CONT TestParseSigningKey/empty_name2512=== CONT TestParseSigningKey/wrong_length2513=== CONT TestParseSigningKey/no_colon2514=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2515=== PAUSE TestExternalSignerErrors/missing_signature_name2516=== RUN TestGenerateFingerprint/invalid_nar_hash_length2517=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2518=== RUN TestSignErrors/canceled2519=== PAUSE TestSignErrors/canceled2520=== CONT TestSignErrors/nil_key2521--- PASS: TestExternalSignerClose (0.00s)2522--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2523=== CONT TestSignErrors/canceled2524=== RUN TestExternalSignerErrors/invalid_signature_base642525=== PAUSE TestExternalSignerErrors/invalid_signature_base642526=== RUN TestGenerateFingerprint/invalid_store_path_prefix2527=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2528=== RUN TestGenerateFingerprint/invalid_reference_prefix2529=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2530=== CONT TestGenerateFingerprint/basic_with_references2531=== CONT TestSignErrors/invalid_narinfo2532=== CONT TestSignErrors/nil_narinfo2533--- PASS: TestParseSigningKey (0.00s)2534 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2535 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2536 --- PASS: TestParseSigningKey/empty_name (0.00s)2537 --- PASS: TestParseSigningKey/wrong_length (0.00s)2538 --- PASS: TestParseSigningKey/no_colon (0.00s)2539 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2540--- PASS: TestExternalSignerWrongPublicKey (0.00s)2541=== RUN TestExternalSignerErrors/exit_at_startup2542=== CONT TestGenerateFingerprint/invalid_nar_hash_length2543=== CONT TestGenerateFingerprint/invalid_reference_prefix2544=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2545=== CONT TestGenerateFingerprint/invalid_store_path_prefix2546=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2547=== CONT TestGenerateFingerprint/no_references2548--- PASS: TestSignErrors (0.00s)2549 --- PASS: TestSignErrors/nil_key (0.00s)2550 --- PASS: TestSignErrors/canceled (0.00s)2551 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2552 --- PASS: TestSignErrors/nil_narinfo (0.00s)2553=== PAUSE TestExternalSignerErrors/exit_at_startup2554--- PASS: TestGenerateFingerprint (0.00s)2555 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2556 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2557 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2558 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2559 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2560 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2561 --- PASS: TestGenerateFingerprint/no_references (0.00s)2562=== RUN TestExternalSignerErrors/wrong_shape2563=== PAUSE TestExternalSignerErrors/wrong_shape2564=== RUN TestExternalSignerErrors/wrong_signature_name2565=== PAUSE TestExternalSignerErrors/wrong_signature_name2566=== RUN TestExternalSignerErrors/invalid_JSON2567=== PAUSE TestExternalSignerErrors/invalid_JSON2568=== RUN TestExternalSignerErrors/missing_signatures2569=== PAUSE TestExternalSignerErrors/missing_signatures2570=== RUN TestExternalSignerErrors/wrong_signatures_shape2571=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2572=== CONT TestExternalSignerErrors/null2573=== CONT TestExternalSignerErrors/wrong_id2574=== CONT TestExternalSignerErrors/too_few_signatures2575=== CONT TestExternalSignerErrors/wrong_signatures_shape2576--- PASS: TestExternalSigner (0.01s)2577=== CONT TestExternalSignerErrors/missing_signatures2578=== CONT TestExternalSignerErrors/invalid_JSON2579=== CONT TestExternalSignerErrors/wrong_signature_name2580=== CONT TestExternalSignerErrors/wrong_shape2581=== CONT TestExternalSignerErrors/exit_at_startup2582=== CONT TestExternalSignerErrors/invalid_signature_base642583=== CONT TestExternalSignerErrors/unrequested_key2584=== CONT TestExternalSignerErrors/null_signatures2585=== CONT TestExternalSignerErrors/program_error2586=== CONT TestExternalSignerErrors/exit_on_request2587=== CONT TestExternalSignerErrors/wrong_signature_length2588=== CONT TestExternalSignerErrors/missing_signature_name2589--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2590--- PASS: TestExternalSignerErrors (0.01s)2591 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2592 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2593 --- PASS: TestExternalSignerErrors/null (0.01s)2594 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2595 --- PASS: TestExternalSignerErrors/program_error (0.00s)2596 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2597 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2598 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2599 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2600 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2601 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2602 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2603 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2604 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2605 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2606 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2607--- PASS: TestExternalSignerCancellation (0.03s)2608PASS2609Running OpenBao signer tests...2610=== RUN TestSign2611=== PAUSE TestSign2612=== RUN TestSignErrors2613=== PAUSE TestSignErrors2614=== RUN TestServe2615=== PAUSE TestServe2616=== RUN TestServeRejectsGarbage2617=== PAUSE TestServeRejectsGarbage2618=== CONT TestSign2619=== CONT TestServe2620=== CONT TestSignErrors2621=== RUN TestSignErrors/invalid_json2622=== PAUSE TestSignErrors/invalid_json2623=== RUN TestSignErrors/no_prefix2624=== PAUSE TestSignErrors/no_prefix2625=== RUN TestSignErrors/invalid_base642626=== PAUSE TestSignErrors/invalid_base642627=== RUN TestSignErrors/http_error2628=== PAUSE TestSignErrors/http_error2629=== CONT TestSignErrors/invalid_json2630=== CONT TestServeRejectsGarbage2631--- PASS: TestServe (0.00s)2632=== CONT TestSignErrors/http_error2633--- PASS: TestServeRejectsGarbage (0.00s)2634=== CONT TestSignErrors/invalid_base642635=== CONT TestSignErrors/no_prefix2636--- PASS: TestSign (0.00s)2637--- PASS: TestSignErrors (0.00s)2638 --- PASS: TestSignErrors/invalid_json (0.00s)2639 --- PASS: TestSignErrors/http_error (0.00s)2640 --- PASS: TestSignErrors/no_prefix (0.00s)2641 --- PASS: TestSignErrors/invalid_base64 (0.00s)2642PASS