niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #366
· 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 TestStreamPushGivesUpOnDeadServer101=== CONT TestScriptTokenEmptyToken102=== CONT TestScriptTokenEmptyCommand103--- PASS: TestScriptTokenEmptyCommand (0.00s)104=== CONT TestUploadMultipart_SupersededByPeer105=== RUN TestUploadMultipart_SupersededByPeer/exists106=== PAUSE TestUploadMultipart_SupersededByPeer/exists107=== RUN TestUploadMultipart_SupersededByPeer/missing108=== PAUSE TestUploadMultipart_SupersededByPeer/missing109=== CONT TestScriptTokenScriptFails110=== CONT TestConvertHashToNix32111=== RUN TestConvertHashToNix32/SRI_format_to_Nix321122026/10/06 08:59:09 ERROR Upload failed error="connection refused" count=20113=== CONT TestScriptTokenBadJSON1142026/10/06 08:59:09 ERROR Server seems unavailable, giving up on batch untried=17115=== CONT TestSetClientTLSDoesNotMutateDefaultTransport116=== CONT TestFileTokenReadsAndCaches117=== CONT TestStaticToken118=== CONT TestEncodeNixBase32119=== CONT TestSetClientTLSErrors120=== CONT TestScriptTokenNoExpiryRerunsEveryCall121=== CONT TestScriptTokenCachesUntilRefresh122=== CONT TestGetStorePathHash123=== RUN TestGetStorePathHash/valid_store_path124=== PAUSE TestGetStorePathHash/valid_store_path125=== RUN TestGetStorePathHash/basename_without_hyphen_should_error126=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error127=== CONT TestStreamPushIsolatesFailures128=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess129=== CONT TestRateLimiterFeedback130=== RUN TestRateLimiterFeedback/429_enables_limiter131=== CONT TestDumpPathSingleFile132=== PAUSE TestRateLimiterFeedback/429_enables_limiter1332026/10/06 08:59:09 WARN Rate limiter enabled after throttle name=server-test rate=51342026/10/06 08:59:09 ERROR Upload failed error="bad path" count=3135=== CONT TestPathInfoCACompatibility136=== RUN TestPathInfoCACompatibility/null_ca_field137=== CONT TestDumpPathMatchesNix138=== CONT TestPathInfoHashCompatibility139=== CONT TestShellSplitErrors140=== CONT TestStreamPushBatchesUnderLoad141=== CONT TestStreamPushReportsEveryPath142=== CONT TestFileTokenMissing143=== CONT TestEncodeNixBase32WithRealHash144=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32145--- PASS: TestScriptTokenScriptFails (0.00s)146=== RUN TestEncodeNixBase32/test_string_hash147=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error148=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error149=== PAUSE TestEncodeNixBase32/test_string_hash150=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error151=== RUN TestRateLimiterFeedback/503_enables_limiter152=== CONT TestParsePathInfoJSON153=== CONT TestParsePathInfoJSONMultiplePaths154=== PAUSE TestPathInfoCACompatibility/null_ca_field155=== CONT TestShellSplit156=== CONT TestFilterOversizedClosures157=== RUN TestFilterOversizedClosures/no_limit_keeps_everything158=== CONT TestFileTokenEmpty159=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)160=== CONT TestCaseHackSuffix161--- PASS: TestStaticToken (0.00s)162=== CONT TestDumpPathWriterError163=== RUN TestEncodeNixBase32/empty_input164=== RUN TestConvertHashToNix32/already_Nix32_format165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon167=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon168=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI169=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== PAUSE TestConvertHashToNix32/already_Nix32_format171=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error172=== PAUSE TestRateLimiterFeedback/503_enables_limiter173=== CONT TestClientSignaturesByStorePath174=== RUN TestConvertHashToNix32/invalid_format175=== CONT TestSetClientTLS176=== RUN TestParsePathInfoJSON/Nix_format177=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun178=== PAUSE TestParsePathInfoJSON/Nix_format179=== PAUSE TestConvertHashToNix32/invalid_format180=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths181=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths182=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths183=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths184=== CONT TestDoWithRetry_BodyReplayedViaGetBody185=== CONT TestUploadMultipart_PartsInParallel186=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything187=== PAUSE TestEncodeNixBase32/empty_input188=== CONT TestPartSizeForNAR189=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped190=== RUN TestPartSizeForNAR/zero_stays_at_minimum191=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum192=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped193--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)194=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512195=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter196=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica197=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter198=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter199=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter200=== RUN TestSetClientTLSErrors/missing_cert_file201=== RUN TestParsePathInfoJSON/Lix_format202=== RUN TestPathInfoCACompatibility/old_string_format_-_text203=== CONT TestRegisterUploadedObjectReusesConnections204=== CONT TestStreamPushReportsSignatures205=== CONT TestStreamPushRequestLine206=== PAUSE TestParsePathInfoJSON/Lix_format207=== RUN TestPartSizeForNAR/small_stays_at_minimum208=== PAUSE TestPartSizeForNAR/small_stays_at_minimum209=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum210=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512211=== RUN TestSetClientTLS/rejects_connection_without_client_cert212=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2132026/10/06 08:59:09 ERROR Upload failed error=boom count=1214=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2152026/10/06 08:59:09 INFO Garbage collection started2162026/10/06 08:59:09 WARN Rate limiter enabled after throttle name=server-test rate=5217=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA2182026/10/06 08:59:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46489219=== RUN TestSetClientTLS/preserves_debug_logging_transport220=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2212026/10/06 08:59:09 ERROR Upload failed error=boom count=1222=== CONT TestUploadMultipart_SupersededByPeer/exists223=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error224=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error225=== CONT TestGetStorePathHash/basename_without_hyphen_should_error226=== CONT TestConvertHashToNix32/SRI_format_to_Nix322272026/10/06 08:59:09 WARN Rate limiter backed off name=server-test rate=5228=== CONT TestConvertHashToNix32/invalid_format2292026/10/06 08:59:09 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46489230=== CONT TestConvertHashToNix32/already_Nix32_format231=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths232=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths233=== CONT TestEncodeNixBase32/test_string_hash234=== CONT TestEncodeNixBase32/empty_input235=== CONT TestRateLimiterFeedback/429_enables_limiter2362026/10/06 08:59:09 INFO Garbage collection started237=== CONT TestUploadMultipart_SupersededByPeer/missing238=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter239=== RUN TestFilterOversizedClosures/all_closures_skipped240=== PAUSE TestFilterOversizedClosures/all_closures_skipped241=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text242=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive243=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive244=== RUN TestPathInfoCACompatibility/new_structured_format_-_text245=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text246=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method247=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method248=== CONT TestRateLimiterFeedback/503_enables_limiter2492026/10/06 08:59:09 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=0250=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2512026/10/06 08:59:09 WARN Rate limiter enabled after throttle name=server-test rate=5252=== RUN TestParsePathInfoJSON/empty_input253=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum2542026/10/06 08:59:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:44201255=== CONT TestResolveStorePath256--- PASS: TestFileTokenReadsAndCaches (0.00s)257=== CONT TestGetStorePathHash/valid_store_path258=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512259=== PAUSE TestParsePathInfoJSON/empty_input260=== CONT TestSetClientTLS/preserves_debug_logging_transport261=== PAUSE TestSetClientTLSErrors/missing_cert_file262--- PASS: TestScriptTokenEmptyToken (0.00s)2632026/10/06 08:59:09 WARN Rate limiter backed off name=server-test rate=5264--- PASS: TestStreamPushIsolatesFailures (0.00s)265--- PASS: TestShellSplitErrors (0.00s)266--- PASS: TestEncodeNixBase32WithRealHash (0.00s)267--- PASS: TestFileTokenMissing (0.00s)268--- PASS: TestStreamPushReportsEveryPath (0.00s)2692026/10/06 08:59:09 WARN Rate limiter enabled after throttle name=server-test rate=5270--- PASS: TestShellSplit (0.00s)2712026/10/06 08:59:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:34127272--- PASS: TestClientSignaturesByStorePath (0.00s)273--- PASS: TestScriptTokenBadJSON (0.01s)274--- PASS: TestFileTokenEmpty (0.00s)275--- PASS: TestDoServerRequestAttachesToken (0.01s)276=== RUN TestSetClientTLSErrors/missing_key_file2772026/10/06 08:59:09 WARN Rate limiter backed off name=server-test rate=5278=== CONT TestPathInfoCACompatibility/null_ca_field279=== CONT TestFilterOversizedClosures/all_closures_skipped2802026/10/06 08:59:09 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=50281=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2822026/10/06 08:59:09 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=2000283=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method284=== CONT TestPathInfoCACompatibility/new_structured_format_-_text285=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestPathInfoCACompatibility/old_string_format_-_text287=== CONT TestFilterOversizedClosures/no_limit_keeps_everything288=== PAUSE TestSetClientTLSErrors/missing_key_file289=== RUN TestSetClientTLSErrors/missing_ca_file290=== PAUSE TestSetClientTLSErrors/missing_ca_file291=== RUN TestSetClientTLSErrors/invalid_ca_file292=== PAUSE TestSetClientTLSErrors/invalid_ca_file293=== CONT TestSetClientTLSErrors/missing_cert_file2942026/10/06 08:59:09 WARN Garbage collection finished on another replica. Its statistics are not available here295=== CONT TestSetClientTLSErrors/invalid_ca_file296=== CONT TestSetClientTLSErrors/missing_key_file297=== CONT TestSetClientTLSErrors/missing_ca_file298=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon299=== RUN TestParsePathInfoJSON/whitespace_only300=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts301=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts302=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA303=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter304--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)305=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)306=== CONT TestSetClientTLS/rejects_connection_without_client_cert307=== PAUSE TestParsePathInfoJSON/whitespace_only308=== RUN TestPartSizeForNAR/1_TiB309=== RUN TestParsePathInfoJSON/invalid_JSON310=== PAUSE TestParsePathInfoJSON/invalid_JSON311=== CONT TestParsePathInfoJSON/Nix_format312=== CONT TestParsePathInfoJSON/whitespace_only313--- PASS: TestStreamPushReportsSignatures (0.00s)314=== CONT TestParsePathInfoJSON/Lix_format315--- PASS: TestConvertHashToNix32 (0.01s)316 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)317 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)318 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)319=== PAUSE TestPartSizeForNAR/1_TiB320=== RUN TestPartSizeForNAR/5_TiB_S3_max_object321=== CONT TestParsePathInfoJSON/invalid_JSON322=== CONT TestParsePathInfoJSON/empty_input323--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)324 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)325 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)326--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)327--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)328=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object329--- PASS: TestResolveStorePath (0.00s)330--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)331--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)332--- PASS: TestDumpPathSingleFile (0.04s)333--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)334--- PASS: TestCaseHackSuffix (0.04s)335--- PASS: TestEncodeNixBase32 (0.01s)336 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)337 --- PASS: TestEncodeNixBase32/empty_input (0.00s)338=== RUN TestPartSizeForNAR/capped_at_5_GiB339=== PAUSE TestPartSizeForNAR/capped_at_5_GiB340=== CONT TestPartSizeForNAR/zero_stays_at_minimum341=== CONT TestPartSizeForNAR/5_TiB_S3_max_object342=== CONT TestPartSizeForNAR/1_TiB343--- PASS: TestGetStorePathHash (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)346 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)347 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)348--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)349 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)350 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)351--- PASS: TestFilterOversizedClosures (0.04s)352 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)353 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)354 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)355--- PASS: TestPathInfoCACompatibility (0.04s)356 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)357 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)358 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)359 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)360 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)361=== CONT TestPartSizeForNAR/capped_at_5_GiB362=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts363=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum364=== CONT TestPartSizeForNAR/small_stays_at_minimum365--- PASS: TestRateLimiterFeedback (0.04s)366 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)367 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)369 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)370--- PASS: TestPathInfoHashCompatibility (0.04s)371 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)372 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)373 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)374 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)375--- PASS: TestParsePathInfoJSON (0.04s)376 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)377 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)378 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)379 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)380 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)381--- PASS: TestSetClientTLSErrors (0.04s)382 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)383 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)384 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)385 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)386--- PASS: TestPartSizeForNAR (0.04s)387 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)388 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)389 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)390 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)391 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)392 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)393 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3942026/10/06 08:59:09 http: TLS handshake error from 127.0.0.1:34022: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.04s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)399--- PASS: TestStreamPushRequestLine (0.02s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)401--- PASS: TestDumpPathWriterError (0.08s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.13s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres985530607/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/postgres985530607/data -l logfile start434435/build/postgres985530607:5432 - no response4362026-10-06 08:59:10.990 UTC [127] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 08:59:10.991 UTC [127] LOG: listening on Unix socket "/build/postgres985530607/.s.PGSQL.5432"4382026-10-06 08:59:10.996 UTC [134] LOG: database system was shut down at 2026-10-06 08:59:10 UTC4392026-10-06 08:59:11.000 UTC [127] LOG: database system is ready to accept connections440/build/postgres985530607:5432 - accepting connections441{"timestamp":"2026-10-06T08:59:11.295183266Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"17ec8b26-4f88-41f6-a4e8-8993824dd548","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(386)"}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 08:59:11 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 08:59:12 INFO lead: released remote=192.0.2.1:12344892026/10/06 08:59:12 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 08:59:13 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.92s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 08:59:13 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 08:59:14.846 UTC [572] FATAL: terminating connection due to administrator command4992026/10/06 08:59:15 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 08:59:16 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 08:59:16 INFO lead: released remote=192.0.2.1:12345022026/10/06 08:59:16 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyContentNegotiation605=== PAUSE TestReadProxyContentNegotiation606=== RUN TestReadProxyNarStreaming607=== PAUSE TestReadProxyNarStreaming608=== RUN TestReadProxy404609=== PAUSE TestReadProxy404610=== RUN TestReadProxyInvalidPath611=== PAUSE TestReadProxyInvalidPath612=== RUN TestReadProxyHead613=== PAUSE TestReadProxyHead614=== RUN TestReadProxyOutlastsServerWriteTimeout615=== PAUSE TestReadProxyOutlastsServerWriteTimeout616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 08:59:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestUploadHandlersRejectOversizedBody693=== CONT TestService_AuthMiddleware694=== CONT TestUploadHandlersRejectInvalidKeys695=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info696=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info697=== CONT TestIsValidUploadKey698=== CONT TestPendingClosureWriteTimeout699=== CONT TestProxyWriteTimeout700=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle701=== CONT TestSkippedUploadsHandler702=== CONT TestParseSize703=== CONT TestService_Rustfstest704=== CONT TestPresignedUploadRegisteredBeforeCommit705=== CONT TestCompletedNarNotReofferedAcrossClosures706=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7072026/10/06 08:59:16 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000708=== CONT TestRedundantMultipartUpload709=== CONT TestPush_SignsNarinfosOfItsPendingObjects710=== CONT TestPush_RejectsBadRequests711=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit712=== CONT TestPush_CompleteCommitsEveryRoot713=== CONT TestPush_OverlappingRootsStoreOneRowPerKey714=== CONT TestReadRedirectUsesPublicS3URL715=== CONT TestReadProxyRangeRequest716=== CONT TestReadRedirectKeepsNarinfoProxied717=== CONT TestReadRedirectNar718=== CONT TestReadProxyDisabled719=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal720=== RUN TestIsValidUploadKey/narinfo721=== RUN TestPendingClosureWriteTimeout/empty722=== RUN TestProxyWriteTimeout/narinfo723--- PASS: TestParseSize (0.00s)724=== CONT TestReadProxyRootRedirectsToIndexHTML725--- PASS: TestSkippedUploadsHandler (0.02s)726=== CONT TestReadProxyConditionalGet727=== PAUSE TestIsValidUploadKey/narinfo728=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal729=== PAUSE TestProxyWriteTimeout/narinfo730=== RUN TestProxyWriteTimeout/1_GiB_nar731=== PAUSE TestProxyWriteTimeout/1_GiB_nar732=== RUN TestProxyWriteTimeout/10_GiB_nar733=== PAUSE TestProxyWriteTimeout/10_GiB_nar734=== RUN TestProxyWriteTimeout/unknown_size735=== PAUSE TestProxyWriteTimeout/unknown_size736=== PAUSE TestPendingClosureWriteTimeout/empty737=== RUN TestPendingClosureWriteTimeout/400_objects738=== PAUSE TestPendingClosureWriteTimeout/400_objects739=== RUN TestPendingClosureWriteTimeout/670k_objects740=== PAUSE TestPendingClosureWriteTimeout/670k_objects741=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline742=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline743=== CONT TestReadProxyOutlastsServerWriteTimeout744=== CONT TestReadProxyHead745=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key746=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key747=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key748=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key749=== RUN TestIsValidUploadKey/nar_zst750=== PAUSE TestIsValidUploadKey/nar_zst751=== RUN TestIsValidUploadKey/nar_xz752=== PAUSE TestIsValidUploadKey/nar_xz753=== RUN TestIsValidUploadKey/nar_plain754=== PAUSE TestIsValidUploadKey/nar_plain755=== RUN TestIsValidUploadKey/listing756=== PAUSE TestIsValidUploadKey/listing757=== RUN TestIsValidUploadKey/build_log758=== PAUSE TestIsValidUploadKey/build_log759=== RUN TestIsValidUploadKey/build_log_home-manager_file760=== PAUSE TestIsValidUploadKey/build_log_home-manager_file761=== RUN TestIsValidUploadKey/build_log_plus_in_name762=== CONT TestReadProxyInvalidPath763=== 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 TestReadProxy404793=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts794=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts795=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure796=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure797=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart798=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart799=== CONT TestReadProxyNarStreaming8002026/10/06 08:59:16 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"801--- PASS: TestService_AuthMiddleware (0.33s)802=== CONT TestReadProxyContentNegotiation8032026/10/06 08:59:16 INFO Received uploads request method=POST path=/api/pending_closures8042026/10/06 08:59:16 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8052026/10/06 08:59:16 INFO Received uploads request method=POST path=/api/pending_closures806--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.37s)807=== CONT TestReadProxyNarinfoAlreadyDecompressed8082026/10/06 08:59:16 INFO Received push request method=POST path=/api/pushes8092026/10/06 08:59:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8102026/10/06 08:59:16 INFO Signed narinfos id=1 count=18112026/10/06 08:59:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8122026/10/06 08:59:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8132026/10/06 08:59:16 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8142026/10/06 08:59:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8152026/10/06 08:59:16 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8162026/10/06 08:59:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8172026/10/06 08:59:16 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18182026/10/06 08:59:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8192026/10/06 08:59:16 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo820--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.38s)821=== CONT TestReadProxyNarinfo8222026/10/06 08:59:16 INFO Received uploads request method=POST path=/api/pending_closures823--- PASS: TestService_Rustfstest (0.43s)824=== CONT TestIsValidCachePath825=== RUN TestIsValidCachePath/narinfo826=== PAUSE TestIsValidCachePath/narinfo827=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars828=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars829=== RUN TestIsValidCachePath/nar_zst830=== PAUSE TestIsValidCachePath/nar_zst831=== RUN TestIsValidCachePath/nar_xz832=== PAUSE TestIsValidCachePath/nar_xz833=== RUN TestIsValidCachePath/nar_bz2834=== PAUSE TestIsValidCachePath/nar_bz2835=== RUN TestIsValidCachePath/nar_uncompressed836=== PAUSE TestIsValidCachePath/nar_uncompressed837=== RUN TestIsValidCachePath/ls838=== PAUSE TestIsValidCachePath/ls839=== RUN TestIsValidCachePath/log840=== PAUSE TestIsValidCachePath/log841=== RUN TestIsValidCachePath/realisation842=== PAUSE TestIsValidCachePath/realisation843=== RUN TestIsValidCachePath/nix-cache-info844=== PAUSE TestIsValidCachePath/nix-cache-info845=== RUN TestIsValidCachePath/index.html846=== PAUSE TestIsValidCachePath/index.html847=== RUN TestIsValidCachePath/traversal_parent848=== PAUSE TestIsValidCachePath/traversal_parent849=== RUN TestIsValidCachePath/traversal_in_middle850=== PAUSE TestIsValidCachePath/traversal_in_middle851=== RUN TestIsValidCachePath/invalid_char_e852=== PAUSE TestIsValidCachePath/invalid_char_e853=== RUN TestIsValidCachePath/invalid_char_u854=== PAUSE TestIsValidCachePath/invalid_char_u855=== RUN TestIsValidCachePath/random_path856=== PAUSE TestIsValidCachePath/random_path857=== RUN TestIsValidCachePath/empty858=== PAUSE TestIsValidCachePath/empty859=== RUN TestIsValidCachePath/leading_slash860=== PAUSE TestIsValidCachePath/leading_slash861=== RUN TestIsValidCachePath/wrong_extension862=== PAUSE TestIsValidCachePath/wrong_extension863=== RUN TestIsValidCachePath/short_hash864=== PAUSE TestIsValidCachePath/short_hash865=== CONT TestProxyHeadersOnlyTrustedOnSocket8662026/10/06 08:59:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8672026/10/06 08:59:16 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLjRkNTFiOWZlLWU0MzQtNDA4Yy1iMzdlLTZlNjZjM2Q2MWNlN3gxNzkxMjc3MTU2ODkyNzA3NDcx8682026/10/06 08:59:16 INFO Received uploads request method=POST path=/api/pending_closures8692026/10/06 08:59:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLjRkNTFiOWZlLWU0MzQtNDA4Yy1iMzdlLTZlNjZjM2Q2MWNlN3gxNzkxMjc3MTU2ODkyNzA3NDcx parts=1870--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.46s)871=== CONT TestParseSingleRange872=== RUN TestParseSingleRange/none873=== PAUSE TestParseSingleRange/none874=== RUN TestParseSingleRange/unknown_unit875=== PAUSE TestParseSingleRange/unknown_unit876=== RUN TestParseSingleRange/multi-range_ignored877=== PAUSE TestParseSingleRange/multi-range_ignored878=== RUN TestParseSingleRange/malformed_no_dash879=== PAUSE TestParseSingleRange/malformed_no_dash880=== RUN TestParseSingleRange/malformed_both_empty881=== PAUSE TestParseSingleRange/malformed_both_empty882=== RUN TestParseSingleRange/malformed_end_before_start883=== PAUSE TestParseSingleRange/malformed_end_before_start884=== RUN TestParseSingleRange/closed885=== PAUSE TestParseSingleRange/closed886=== RUN TestParseSingleRange/open-ended887=== PAUSE TestParseSingleRange/open-ended888=== RUN TestParseSingleRange/end_clamped_to_size889=== PAUSE TestParseSingleRange/end_clamped_to_size890=== RUN TestParseSingleRange/suffix891=== PAUSE TestParseSingleRange/suffix892=== RUN TestParseSingleRange/suffix_exceeds_size893=== PAUSE TestParseSingleRange/suffix_exceeds_size894=== RUN TestParseSingleRange/single_byte895=== PAUSE TestParseSingleRange/single_byte896=== RUN TestParseSingleRange/start_past_EOF897=== PAUSE TestParseSingleRange/start_past_EOF898=== RUN TestParseSingleRange/start_far_past_EOF899=== PAUSE TestParseSingleRange/start_far_past_EOF900=== CONT TestPresentNotReportedWhileGCDeletesClosure9012026/10/06 08:59:16 INFO Received uploads request method=POST path=/api/pending_closures9022026/10/06 08:59:17 INFO Received push request method=POST path=/api/pushes903--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.53s)904=== CONT TestPresentReportsOnlyClosureRoots905--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.54s)906=== CONT TestCreatePin_ReservedPins907=== RUN TestPush_RejectsBadRequests/no_roots908=== PAUSE TestPush_RejectsBadRequests/no_roots909=== RUN TestPush_RejectsBadRequests/no_objects910=== PAUSE TestPush_RejectsBadRequests/no_objects911=== RUN TestPush_RejectsBadRequests/bad_root912=== PAUSE TestPush_RejectsBadRequests/bad_root913=== RUN TestPush_RejectsBadRequests/root_not_in_objects914=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects915=== CONT TestOrphanedObjectsGCStressTest9162026/10/06 08:59:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete917--- PASS: TestReadRedirectNar (0.59s)918=== CONT TestOrphanedObjectsGC9192026/10/06 08:59:17 INFO Received push request method=POST path=/api/pushes9202026/10/06 08:59:17 INFO Received complete push request method=POST path=/api/pushes/1/complete9212026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures9222026/10/06 08:59:17 INFO Received push request method=POST path=/api/pushes9232026/10/06 08:59:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43799/oidc9242026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures925--- PASS: TestReadRedirectUsesPublicS3URL (0.61s)926=== CONT TestObjectStatsTrigger927--- PASS: TestReadProxyConditionalGet (0.64s)928=== CONT TestPendingCleanupUsesOneCutoff9292026/10/06 08:59:17 INFO Aborted multipart uploads count=0 kept=09302026/10/06 08:59:17 WARN Force mode enabled - objects will be deleted immediately without grace period9312026/10/06 08:59:17 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=0932--- PASS: TestReadRedirectKeepsNarinfoProxied (0.66s)933=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9342026/10/06 08:59:17 INFO Vacuumed table table=pending_closures9352026/10/06 08:59:17 INFO Vacuumed table table=pending_objects9362026/10/06 08:59:17 INFO Vacuumed table table=multipart_uploads9372026/10/06 08:59:17 INFO Vacuumed table table=closures9382026/10/06 08:59:17 INFO Vacuumed table table=objects9392026/10/06 08:59:17 INFO Received push request method=POST path=/api/pushes9402026/10/06 08:59:17 INFO Received complete push request method=POST path=/api/pushes/2/complete941--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.76s)942=== CONT TestMultipartCleanup9432026/10/06 08:59:17 INFO Received complete push request method=POST path=/api/pushes/1/complete944--- PASS: TestReadProxyDisabled (0.78s)945=== CONT TestServerTLSConfig946=== RUN TestServerTLSConfig/no_client_CA947=== PAUSE TestServerTLSConfig/no_client_CA948=== RUN TestServerTLSConfig/missing_CA_file949=== PAUSE TestServerTLSConfig/missing_CA_file950=== RUN TestServerTLSConfig/not_a_PEM_file951=== PAUSE TestServerTLSConfig/not_a_PEM_file952=== CONT TestService_NativeMTLS953--- PASS: TestPush_CompleteCommitsEveryRoot (0.72s)954=== CONT TestMetricsInventory955--- PASS: TestReadProxyInvalidPath (0.74s)956=== CONT TestNARDeduplicationMetadataUploadBug957--- PASS: TestReadProxyRangeRequest (0.78s)958=== CONT TestCreatePendingClosureRejectsOversizedNAR9592026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures960--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)961=== CONT TestCacheConfigHandlerMaxNarSize962--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)963=== CONT TestGenerateLandingPage964--- PASS: TestGenerateLandingPage (0.00s)965=== CONT TestService_readinessHandler966--- PASS: TestReadProxyHead (0.80s)967=== CONT TestService_healthCheckHandler968--- PASS: TestReadProxyNarStreaming (0.77s)969=== CONT TestGracefulShutdownDrainsInflight9702026/10/06 08:59:17 INFO Starting HTTP server address=127.0.0.1:415359712026/10/06 08:59:17 INFO Shutdown signal received, draining in-flight requests timeout=10s972--- PASS: TestReadProxy404 (0.89s)973=== CONT TestGCTaskStore_Fail974--- PASS: TestGCTaskStore_Fail (0.00s)975=== CONT TestService_verifyS3Integrity976--- PASS: TestGracefulShutdownDrainsInflight (0.07s)977=== CONT TestGCTaskStore_PhaseUpdates978--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)979=== CONT TestGCTaskStore_CompletedAllowsNewTask980--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)981=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9822026/10/06 08:59:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete983--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.65s)984=== CONT TestGCTaskStore_GetReturnsLatest985--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)986=== CONT TestCompleteMultipartUnregistered9872026/10/06 08:59:17 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLjk2Zjk5OGVhLWQ2MzQtNDllMi05YzA2LWUwNjBjMzk5ZmM3Y3gxNzkxMjc3MTU2OTUyNDEyMTM3 parts=129882026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures989--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.02s)990=== CONT TestGCTaskStore_GetEmpty991--- PASS: TestGCTaskStore_GetEmpty (0.00s)992=== CONT TestGCTaskStore_ConflictDifferentParams993--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)994=== CONT TestGCTaskStore_DeduplicateSameParams995--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)996=== CONT TestService_createPendingClosureHandler997--- PASS: TestReadProxyContentNegotiation (0.71s)998=== CONT TestGCTaskStore_StartNew999--- PASS: TestGCTaskStore_StartNew (0.00s)1000=== CONT TestGCEndsOnShutdown1001=== RUN TestGCEndsOnShutdown/before_the_run1002=== PAUSE TestGCEndsOnShutdown/before_the_run1003=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1004=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1005=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1006=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1007=== CONT TestCommitRacingPendingCleanupKeepsObjects10082026/10/06 08:59:17 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket461715804/001/proxy.sock10092026/10/06 08:59:17 INFO Starting HTTP server address=127.0.0.1:4078910102026/10/06 08:59:17 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10112026/10/06 08:59:17 INFO Shutdown signal received, draining in-flight requests timeout=10s1012--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.63s)1013=== CONT TestResolveDBConnectionString1014=== RUN TestResolveDBConnectionString/flag_wins1015=== PAUSE TestResolveDBConnectionString/flag_wins1016=== RUN TestResolveDBConnectionString/file_when_flag_empty1017=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1018=== RUN TestResolveDBConnectionString/missing_file_is_an_error1019=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1020=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1021=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1022=== RUN TestResolveDBConnectionString/nothing_configured1023=== PAUSE TestResolveDBConnectionString/nothing_configured1024=== CONT TestConnectWaitsForAPeerMigration10252026/10/06 08:59:17 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1026--- PASS: TestReadProxyNarinfo (0.75s)1027=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1028--- PASS: TestPresentReportsOnlyClosureRoots (0.59s)1029=== CONT TestClientFallsBackToClosures10302026/10/06 08:59:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10312026/10/06 08:59:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLjVjOThjN2Q3LTEyNTMtNDBmMC04YTA2LTY0NzBhNGFlOTE3Y3gxNzkxMjc3MTU3MTQwMzE1NTQy parts=1210322026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/06 08:59:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10342026/10/06 08:59:17 WARN Refused reserved pin name=worker-x86_64-linux10352026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/06 08:59:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10372026/10/06 08:59:17 INFO Received create pin request method=POST path=/api/pins/my-app10382026/10/06 08:59:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1039--- PASS: TestCreatePin_ReservedPins (0.68s)1040=== CONT TestPushWaitsForSweepHoldingRow10412026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures1042--- PASS: TestObjectStatsTrigger (0.59s)1043=== CONT TestClientPushesUseOnePush10442026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures10452026/10/06 08:59:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10462026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures1047--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.59s)1048=== CONT TestPinProtectsFromGC10492026/10/06 08:59:17 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/06 08:59:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10512026/10/06 08:59:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1052--- PASS: TestService_NativeMTLS (0.58s)1053=== CONT TestSweepRechecksPendingAfterLocking1054--- PASS: TestMetricsInventory (0.62s)1055=== CONT TestClientSharedPathCommittedMidPush10562026/10/06 08:59:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10572026/10/06 08:59:17 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10582026/10/06 08:59:17 INFO Aborted multipart uploads count=0 kept=110592026/10/06 08:59:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10602026/10/06 08:59:17 INFO Aborted multipart uploads count=1 kept=01061--- PASS: TestMultipartCleanup (0.70s)1062=== CONT TestClientWithDependencies1063=== NAME TestNARDeduplicationMetadataUploadBug1064 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1247390140/001/store/70r1ds3c0xfyz905912sb2gwc5dldb45-file1.txt10652026/10/06 08:59:17 WARN readiness check failed error="closed pool"1066--- PASS: TestService_readinessHandler (0.62s)1067=== CONT TestGetExistingObjectsLocksRows1068--- PASS: TestService_healthCheckHandler (0.63s)1069=== CONT TestClientMultipleUploads1070=== NAME TestOrphanedObjectsGC1071 orphaned_objects_gc_test.go:290: GC Test Summary:1072 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1073 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1074 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1075 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1076 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1077--- PASS: TestOrphanedObjectsGC (0.94s)1078=== CONT TestClientIntegration10792026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures10802026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes10812026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures10822026/10/06 08:59:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10832026/10/06 08:59:18 INFO Uploading 70r1ds3c0xfyz905912sb2gwc5dldb45-file1.txt (160B)10842026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10852026/10/06 08:59:18 WARN Failed to register uploaded object key=70r1ds3c0xfyz905912sb2gwc5dldb45.ls error="server returned 404: 404 page not found\n"10862026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10872026/10/06 08:59:18 INFO Signed narinfos id=1 count=110882026/10/06 08:59:18 INFO Uploading 1 narinfos1089--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.62s)1090=== CONT TestClientErrorHandling1091=== RUN TestClientErrorHandling/InvalidStorePath1092=== PAUSE TestClientErrorHandling/InvalidStorePath1093=== RUN TestClientErrorHandling/InvalidAuthToken1094=== PAUSE TestClientErrorHandling/InvalidAuthToken1095=== RUN TestClientErrorHandling/ServerNotAvailable1096=== PAUSE TestClientErrorHandling/ServerNotAvailable1097=== CONT TestRegisterCompletedObjectNeedsPendingRow10982026/10/06 08:59:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1099--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.14s)11002026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete1101=== CONT TestClientCADerivations11022026/10/06 08:59:18 WARN Failed to register uploaded object key=70r1ds3c0xfyz905912sb2gwc5dldb45.narinfo error="server returned 404: 404 page not found\n"11032026/10/06 08:59:18 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1104--- PASS: TestCompleteMultipartUnregistered (0.59s)1105=== CONT TestCacheStatsHandler11062026/10/06 08:59:18 INFO Upload complete. (90ms)1107=== NAME TestNARDeduplicationMetadataUploadBug1108 metadata_upload_test.go:54: Retrieved narinfo from S3:1109 StorePath: /build/TestNARDeduplicationMetadataUploadBug1247390140/001/store/70r1ds3c0xfyz905912sb2gwc5dldb45-file1.txt1110 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1111 Compression: zstd1112 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1113 NarSize: 1601114 References: 1115 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1116 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1117 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1118 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11192026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures11202026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures11212026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures1122 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1247390140/001/store/3cdf1hy7xpsqz78n6fa136bxf9ckb10w-file2.txt11232026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=011242026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period11252026/10/06 08:59:18 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=011262026/10/06 08:59:18 INFO Vacuumed table table=pending_closures11272026/10/06 08:59:18 INFO Vacuumed table table=pending_objects11282026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads11292026/10/06 08:59:18 INFO Vacuumed table table=closures11302026/10/06 08:59:18 INFO Vacuumed table table=objects1131--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.69s)1132=== CONT TestSweepSkipsRowsLockedByPush11332026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes11342026/10/06 08:59:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11352026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11362026/10/06 08:59:18 INFO Signed narinfos id=2 count=111372026/10/06 08:59:18 WARN Failed to register uploaded object key=3cdf1hy7xpsqz78n6fa136bxf9ckb10w.ls error="server returned 404: 404 page not found\n"11382026/10/06 08:59:18 INFO Uploading 1 narinfos11392026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/2/complete11402026/10/06 08:59:18 WARN Failed to register uploaded object key=3cdf1hy7xpsqz78n6fa136bxf9ckb10w.narinfo error="server returned 404: 404 page not found\n"11412026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures11422026/10/06 08:59:18 INFO Upload complete. (71ms)1143=== NAME TestNARDeduplicationMetadataUploadBug1144 metadata_upload_test.go:76: Retrieved narinfo from S3:1145 StorePath: /build/TestNARDeduplicationMetadataUploadBug1247390140/001/store/3cdf1hy7xpsqz78n6fa136bxf9ckb10w-file2.txt1146 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1147 Compression: zstd1148 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1149 NarSize: 1601150 References: 1151 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1152 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1153 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1154 {"version":1,"root":{"type":"regular","size":44}}1155--- PASS: TestNARDeduplicationMetadataUploadBug (0.95s)1156=== CONT TestCacheConfigHandler1157=== RUN TestCacheConfigHandler/full_config,_no_issuer1158=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1159=== RUN TestCacheConfigHandler/no_cache_url_configured1160=== PAUSE TestCacheConfigHandler/no_cache_url_configured1161=== RUN TestCacheConfigHandler/no_signing_keys1162=== PAUSE TestCacheConfigHandler/no_signing_keys1163=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1164=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1165=== CONT TestFailedS3DeleteKeepsTombstone11662026/10/06 08:59:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11672026/10/06 08:59:18 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLjhjYjY2YmEyLTk0ZGMtNDEzMC1hODBjLTU4NDk4OGVkMDA1ZXgxNzkxMjc3MTU3NzEzNzkzNjMy error="Get \"http://127.0.0.1:1/bucket15/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11682026/10/06 08:59:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLjEyMmIxMTU5LThmMDMtNGNjNS1iMTExLTBiNDNhOWRlMDk0OHgxNzkxMjc3MTU3NzA2MzI5NTg0 parts=1211692026/10/06 08:59:18 INFO Received cleanup request method=DELETE path=/api/pending_closures11702026/10/06 08:59:18 INFO Aborted multipart uploads count=1 kept=01171--- PASS: TestRedundantMultipartUpload (1.81s)1172=== CONT TestService_ReadScope_PublicByDefault11732026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=011742026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period11752026/10/06 08:59:18 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=011762026/10/06 08:59:18 INFO Vacuumed table table=pending_closures11772026/10/06 08:59:18 INFO Vacuumed table table=pending_objects11782026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads11792026/10/06 08:59:18 INFO Vacuumed table table=closures11802026/10/06 08:59:18 INFO Vacuumed table table=objects1181--- PASS: TestSweepRechecksPendingAfterLocking (0.53s)1182=== CONT TestForceGCDuringPushOffersSweptObject1183=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1184=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1185=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1186=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1187=== CONT TestService_RequireScope_OIDC1188=== NAME TestPinProtectsFromGC1189 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC838844497/001/store/k2wyrpinkjcngr7spj6xqbpfp7w4v3ba-pinned-file.txt1190 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC838844497/001/store/a2hr46a86533z272z9pfi808lj06m02n-unpinned-file.txt1191--- PASS: TestGetExistingObjectsLocksRows (0.46s)1192=== CONT TestService_AuthMiddleware_OIDC11932026/10/06 08:59:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45659/oidc11942026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures11952026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures11962026/10/06 08:59:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11972026/10/06 08:59:18 INFO Uploading cncp76wh8i3dwc5547wb9s876rr20885-shared-dep (136B)11982026/10/06 08:59:18 INFO Uploading siyx2pclr9fq3smsxv1afdfjiqn01ksv-a (216B)11992026/10/06 08:59:18 WARN Failed to register uploaded object key=6d9nxn47dwpl9x035cl77293gxbzc3ch.ls error="server returned 404: 404 page not found\n"12002026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12012026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1fiypr6wyw0f6v643kihfan5j3cywg561yf9rlhqcq36zl6pn23m.nar.zst error="server returned 404: 404 page not found\n"12022026/10/06 08:59:18 WARN Failed to register uploaded object key=siyx2pclr9fq3smsxv1afdfjiqn01ksv.ls error="server returned 404: 404 page not found\n"12032026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12042026/10/06 08:59:18 WARN Failed to register uploaded object key=cncp76wh8i3dwc5547wb9s876rr20885.ls error="server returned 404: 404 page not found\n"12052026/10/06 08:59:18 INFO Signed narinfos id=2 count=212062026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12072026/10/06 08:59:18 INFO Signed narinfos id=1 count=212082026/10/06 08:59:18 INFO Uploading 4 narinfos12092026/10/06 08:59:18 WARN Failed to register uploaded object key=siyx2pclr9fq3smsxv1afdfjiqn01ksv.narinfo error="server returned 404: 404 page not found\n"12102026/10/06 08:59:18 WARN Failed to register uploaded object key=6d9nxn47dwpl9x035cl77293gxbzc3ch.narinfo error="server returned 404: 404 page not found\n"12112026/10/06 08:59:18 WARN Failed to register uploaded object key=cncp76wh8i3dwc5547wb9s876rr20885.narinfo error="server returned 404: 404 page not found\n"12122026/10/06 08:59:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12132026/10/06 08:59:18 WARN Failed to register uploaded object key=cncp76wh8i3dwc5547wb9s876rr20885.narinfo error="server returned 404: 404 page not found\n"12142026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes1215=== NAME TestClientMultipleUploads1216 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2181042362/001/store/w8yw37pmqsqml08sa8ql79cf6rax34zy-test-file-0.txt1217--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.87s)1218=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12192026/10/06 08:59:18 INFO Completed upload id=112202026/10/06 08:59:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12212026/10/06 08:59:18 INFO Uploading k2wyrpinkjcngr7spj6xqbpfp7w4v3ba-pinned-file.txt (128B)12222026/10/06 08:59:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12232026/10/06 08:59:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12242026/10/06 08:59:18 INFO Completed upload id=212252026/10/06 08:59:18 INFO Upload complete. (83ms)1226=== NAME TestClientFallsBackToClosures1227 client_pushes_test.go:112: Retrieved narinfo from S3:1228 StorePath: /build/TestClientFallsBackToClosures3082565734/001/store/cncp76wh8i3dwc5547wb9s876rr20885-shared-dep1229 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1230 Compression: zstd1231 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821232 NarSize: 1361233 References: 1234 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12352026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12362026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12372026/10/06 08:59:18 WARN Failed to register uploaded object key=k2wyrpinkjcngr7spj6xqbpfp7w4v3ba.ls error="server returned 404: 404 page not found\n"1238--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.42s)1239=== CONT TestService_ReadAuthMiddleware12402026/10/06 08:59:18 INFO Signed narinfos id=1 count=112412026/10/06 08:59:18 INFO Uploading 1 narinfos1242=== NAME TestClientFallsBackToClosures1243 client_pushes_test.go:112: Retrieved narinfo from S3:1244 StorePath: /build/TestClientFallsBackToClosures3082565734/001/store/siyx2pclr9fq3smsxv1afdfjiqn01ksv-a1245 URL: nar/1fiypr6wyw0f6v643kihfan5j3cywg561yf9rlhqcq36zl6pn23m.nar.zst1246 Compression: zstd1247 NarHash: sha256:1fiypr6wyw0f6v643kihfan5j3cywg561yf9rlhqcq36zl6pn23m1248 NarSize: 2161249 References: /build/TestClientFallsBackToClosures3082565734/001/store/cncp76wh8i3dwc5547wb9s876rr20885-shared-dep1250 CA: text:sha256:0f0y5dlwmsfhgdbk5xcyscg469bvs3i67x77pyynvmq4kg554nli12512026/10/06 08:59:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42783/oidc1252=== NAME TestClientWithDependencies1253 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies4181096008/001/store/k4637gakhnp78j63wnhzxdc3jcw1kpxq-test-script12542026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes1255=== NAME TestClientFallsBackToClosures1256 client_pushes_test.go:112: Retrieved narinfo from S3:1257 StorePath: /build/TestClientFallsBackToClosures3082565734/001/store/6d9nxn47dwpl9x035cl77293gxbzc3ch-b1258 URL: nar/1fiypr6wyw0f6v643kihfan5j3cywg561yf9rlhqcq36zl6pn23m.nar.zst1259 Compression: zstd1260 NarHash: sha256:1fiypr6wyw0f6v643kihfan5j3cywg561yf9rlhqcq36zl6pn23m1261 NarSize: 2161262 References: /build/TestClientFallsBackToClosures3082565734/001/store/cncp76wh8i3dwc5547wb9s876rr20885-shared-dep1263 CA: text:sha256:0f0y5dlwmsfhgdbk5xcyscg469bvs3i67x77pyynvmq4kg554nli12642026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete12652026/10/06 08:59:18 WARN Failed to register uploaded object key=k2wyrpinkjcngr7spj6xqbpfp7w4v3ba.narinfo error="server returned 404: 404 page not found\n"1266--- PASS: TestClientFallsBackToClosures (0.89s)1267=== CONT TestGCSweepDeliversEachKeyOnce12682026/10/06 08:59:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLmM0YmRiZGJiLWYyYzMtNDE1NC04NmE5LWVhMDlmZDIyMGU1OXgxNzkxMjc3MTU4MDMzMzcxNjAw parts=1012692026/10/06 08:59:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12702026/10/06 08:59:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12712026/10/06 08:59:18 INFO Uploading 8jlz8hlfjbmp9rrj2ffi9fx7xv31jmrx-shared-dep (136B)12722026/10/06 08:59:18 INFO Uploading 82z2611q7f8722jkyi82bq74q9fndkrp-b (216B)12732026/10/06 08:59:18 INFO Completed upload id=112742026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures12752026/10/06 08:59:18 WARN Failed to register uploaded object key=p1fyvrw6vyryg714fqdnl3dqn6li0d12.ls error="server returned 404: 404 page not found\n"12762026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/0395mqd4aa2cmsnccxpdqvscarsx12ializjf5p2xw2il24zb0fx.nar.zst error="server returned 404: 404 page not found\n"12772026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12782026/10/06 08:59:18 WARN Failed to register uploaded object key=8jlz8hlfjbmp9rrj2ffi9fx7xv31jmrx.ls error="server returned 404: 404 page not found\n"12792026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12802026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures12812026/10/06 08:59:18 INFO Signed narinfos id=1 count=312822026/10/06 08:59:18 WARN Failed to register uploaded object key=82z2611q7f8722jkyi82bq74q9fndkrp.ls error="server returned 404: 404 page not found\n"12832026/10/06 08:59:18 INFO Uploading 3 narinfos12842026/10/06 08:59:18 INFO Upload complete. (74ms)12852026/10/06 08:59:18 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12862026/10/06 08:59:18 WARN Found objects in DB but missing from S3, will re-upload count=11287--- PASS: TestService_verifyS3Integrity (1.07s)1288=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12892026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes12902026/10/06 08:59:18 WARN Failed to register uploaded object key=82z2611q7f8722jkyi82bq74q9fndkrp.narinfo error="server returned 404: 404 page not found\n"12912026/10/06 08:59:18 WARN Failed to register uploaded object key=p1fyvrw6vyryg714fqdnl3dqn6li0d12.narinfo error="server returned 404: 404 page not found\n"12922026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete12932026/10/06 08:59:18 WARN Failed to register uploaded object key=8jlz8hlfjbmp9rrj2ffi9fx7xv31jmrx.narinfo error="server returned 404: 404 page not found\n"1294=== NAME TestClientMultipleUploads1295 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2181042362/001/store/bix02g0wb18ymwm3nkifycb3zywnfady-test-file-1.txt12962026/10/06 08:59:18 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12972026/10/06 08:59:18 INFO Uploading ifgpm6a0mrafmplcazi3782lpmr51nzl-shared-dep (136B)12982026/10/06 08:59:18 INFO Uploading 746xsjzwzsppsrnqql325vh2x7alv4jl-top (224B)1299=== NAME TestClientIntegration1300 client_integration_test.go:286: Created store path: /build/TestClientIntegration2757966493/002/store/4jb4d9h7bjd8fdnqa6id3ylixv3b2kpj-test-file.txt13012026/10/06 08:59:18 WARN Failed to register uploaded object key=ifgpm6a0mrafmplcazi3782lpmr51nzl.ls error="server returned 404: 404 page not found\n"13022026/10/06 08:59:18 WARN Failed to register uploaded object key=746xsjzwzsppsrnqql325vh2x7alv4jl.ls error="server returned 404: 404 page not found\n"13032026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13042026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13052026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1pianchx1y6ficzaq8gvy9xg9dynyahbgava0xm9znr9g7f307lm.nar.zst error="server returned 404: 404 page not found\n"13062026/10/06 08:59:18 INFO Signed narinfos id=1 count=213072026/10/06 08:59:18 INFO Uploading 2 narinfos13082026/10/06 08:59:18 WARN Failed to register uploaded object key=ifgpm6a0mrafmplcazi3782lpmr51nzl.narinfo error="server returned 404: 404 page not found\n"13092026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete13102026/10/06 08:59:18 WARN Failed to register uploaded object key=746xsjzwzsppsrnqql325vh2x7alv4jl.narinfo error="server returned 404: 404 page not found\n"1311=== NAME TestClientWithDependencies1312 client_integration_test.go:615: Found 1 dependencies (including self)13132026/10/06 08:59:18 INFO Upload complete. (94ms)13142026/10/06 08:59:18 INFO Upload complete. (60ms)1315=== NAME TestClientSharedPathCommittedMidPush1316 client_integration_test.go:680: Retrieved narinfo from S3:1317 StorePath: /build/TestClientSharedPathCommittedMidPush2688735177/001/store/ifgpm6a0mrafmplcazi3782lpmr51nzl-shared-dep1318 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1319 Compression: zstd1320 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821321 NarSize: 1361322 References: 1323 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1324=== NAME TestClientPushesUseOnePush1325 client_pushes_test.go:97: Retrieved narinfo from S3:1326 StorePath: /build/TestClientPushesUseOnePush1514277206/001/store/8jlz8hlfjbmp9rrj2ffi9fx7xv31jmrx-shared-dep1327 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1328 Compression: zstd1329 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821330 NarSize: 1361331 References: 1332 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1333=== NAME TestClientSharedPathCommittedMidPush1334 client_integration_test.go:680: Retrieved narinfo from S3:1335 StorePath: /build/TestClientSharedPathCommittedMidPush2688735177/001/store/746xsjzwzsppsrnqql325vh2x7alv4jl-top1336 URL: nar/1pianchx1y6ficzaq8gvy9xg9dynyahbgava0xm9znr9g7f307lm.nar.zst1337 Compression: zstd1338 NarHash: sha256:1pianchx1y6ficzaq8gvy9xg9dynyahbgava0xm9znr9g7f307lm1339 NarSize: 2241340 References: /build/TestClientSharedPathCommittedMidPush2688735177/001/store/ifgpm6a0mrafmplcazi3782lpmr51nzl-shared-dep1341 CA: text:sha256:0vjaiclmywc7yf3pvcx0fvsh5g0442rsxf828il7bym1dsildy0z1342=== NAME TestClientPushesUseOnePush1343 client_pushes_test.go:97: Retrieved narinfo from S3:1344 StorePath: /build/TestClientPushesUseOnePush1514277206/001/store/p1fyvrw6vyryg714fqdnl3dqn6li0d12-a1345 URL: nar/0395mqd4aa2cmsnccxpdqvscarsx12ializjf5p2xw2il24zb0fx.nar.zst1346 Compression: zstd1347 NarHash: sha256:0395mqd4aa2cmsnccxpdqvscarsx12ializjf5p2xw2il24zb0fx1348 NarSize: 2161349 References: /build/TestClientPushesUseOnePush1514277206/001/store/8jlz8hlfjbmp9rrj2ffi9fx7xv31jmrx-shared-dep1350 CA: text:sha256:0fkr59zjw8s84b9f7pshprijpjywx1wrffp8nkm8lnyhllq5rvsl1351 client_pushes_test.go:97: Retrieved narinfo from S3:1352 StorePath: /build/TestClientPushesUseOnePush1514277206/001/store/82z2611q7f8722jkyi82bq74q9fndkrp-b1353 URL: nar/0395mqd4aa2cmsnccxpdqvscarsx12ializjf5p2xw2il24zb0fx.nar.zst1354 Compression: zstd1355 NarHash: sha256:0395mqd4aa2cmsnccxpdqvscarsx12ializjf5p2xw2il24zb0fx1356 NarSize: 2161357 References: /build/TestClientPushesUseOnePush1514277206/001/store/8jlz8hlfjbmp9rrj2ffi9fx7xv31jmrx-shared-dep1358 CA: text:sha256:0fkr59zjw8s84b9f7pshprijpjywx1wrffp8nkm8lnyhllq5rvsl1359--- PASS: TestClientSharedPathCommittedMidPush (0.65s)1360=== CONT TestTombstonedObjectOfferedWithoutWaiting1361--- PASS: TestClientPushesUseOnePush (0.80s)1362=== CONT TestService_AuthMiddleware_MTLSProxyHeader1363--- PASS: TestCacheStatsHandler (0.48s)1364=== NAME TestClientMultipleUploads1365 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2181042362/001/store/pdxdvipd6rd49l6npdr6hsiysnqca8mw-test-file-2.txt1366=== CONT TestGCSweepSkipsPendingObjects13672026/10/06 08:59:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13682026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes13692026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes13702026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=013712026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period13722026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures13732026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes13742026/10/06 08:59:18 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=013752026/10/06 08:59:18 INFO Vacuumed table table=pending_closures13762026/10/06 08:59:18 INFO Vacuumed table table=pending_objects13772026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads13782026/10/06 08:59:18 INFO Vacuumed table table=closures13792026/10/06 08:59:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13802026/10/06 08:59:18 INFO Uploading a2hr46a86533z272z9pfi808lj06m02n-unpinned-file.txt (128B)13812026/10/06 08:59:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13822026/10/06 08:59:18 INFO Vacuumed table table=objects13832026/10/06 08:59:18 INFO Uploading 4jb4d9h7bjd8fdnqa6id3ylixv3b2kpj-test-file.txt (152B)13842026/10/06 08:59:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=N2NlMWY5NmMtYTczMi00NTVhLWI2NjYtZmI1ZDc4ODUyMzhhLjVjMTBlNWMxLTA2OWQtNGMzYS1hNmNmLTk3NWNhODA0ZjVhMHgxNzkxMjc3MTU4MTI4MDE5OTAy parts=1013852026/10/06 08:59:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13862026/10/06 08:59:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13872026/10/06 08:59:18 INFO Uploading k4637gakhnp78j63wnhzxdc3jcw1kpxq-test-script (136B)13882026/10/06 08:59:18 WARN Failed to register uploaded object key=a2hr46a86533z272z9pfi808lj06m02n.ls error="server returned 404: 404 page not found\n"13892026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13902026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=013912026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13922026/10/06 08:59:18 WARN Failed to register uploaded object key=4jb4d9h7bjd8fdnqa6id3ylixv3b2kpj.ls error="server returned 404: 404 page not found\n"13932026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13942026/10/06 08:59:18 INFO Completed upload id=113952026/10/06 08:59:18 INFO Signed narinfos id=2 count=113962026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13972026/10/06 08:59:18 INFO Signed narinfos id=1 count=113982026/10/06 08:59:18 INFO Uploading 1 narinfos13992026/10/06 08:59:18 INFO Uploading 1 narinfos14002026/10/06 08:59:18 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014012026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period14022026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures1403=== NAME TestClientCADerivations1404 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4254186630/001/store/hxfibyaapcbdnx2q9rc6j3m7h7080naq-ca-test14052026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14062026/10/06 08:59:18 WARN Failed to register uploaded object key=log/dgzxwjazb3nkdcn1hzsvpfp2v1zcfnyh-test-script.drv error="server returned 404: 404 page not found\n"14072026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14082026/10/06 08:59:18 INFO Signed narinfos id=1 count=114092026/10/06 08:59:18 WARN Failed to register uploaded object key=k4637gakhnp78j63wnhzxdc3jcw1kpxq.ls error="server returned 404: 404 page not found\n"14102026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete14112026/10/06 08:59:18 INFO Uploading 1 narinfos14122026/10/06 08:59:18 WARN Failed to register uploaded object key=4jb4d9h7bjd8fdnqa6id3ylixv3b2kpj.narinfo error="server returned 404: 404 page not found\n"14132026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/2/complete14142026/10/06 08:59:18 WARN Failed to register uploaded object key=a2hr46a86533z272z9pfi808lj06m02n.narinfo error="server returned 404: 404 page not found\n"14152026/10/06 08:59:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures14162026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete14172026/10/06 08:59:18 INFO Upload complete. (57ms)14182026/10/06 08:59:18 WARN Failed to register uploaded object key=k4637gakhnp78j63wnhzxdc3jcw1kpxq.narinfo error="server returned 404: 404 page not found\n"14192026/10/06 08:59:18 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=014202026/10/06 08:59:18 INFO Vacuumed table table=pending_closures14212026/10/06 08:59:18 INFO Vacuumed table table=pending_objects14222026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads14232026/10/06 08:59:18 INFO Vacuumed table table=closures14242026/10/06 08:59:18 INFO Upload complete. (70ms)14252026/10/06 08:59:18 INFO Upload complete. (62ms)14262026/10/06 08:59:18 INFO Vacuumed table table=objects1427--- PASS: TestSweepSkipsRowsLockedByPush (0.43s)1428=== CONT TestService_cleanupPendingClosuresHandler14292026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=01430=== NAME TestClientWithDependencies1431 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4181096008/001/store) requires matching store prefix1432--- PASS: TestService_ReadScope_PublicByDefault (0.34s)1433=== CONT TestDeduplicatedObjectsRecordedAsPending1434--- PASS: TestClientWithDependencies (0.69s)1435=== CONT TestGCAdvisoryLockBlocksConcurrentRun14362026/10/06 08:59:18 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=014372026/10/06 08:59:18 INFO Vacuumed table table=pending_closures14382026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes14392026/10/06 08:59:18 INFO Vacuumed table table=pending_objects1440=== NAME TestClientCADerivations14412026/10/06 08:59:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1442 client_ca_test.go:139: Found 1 dependencies (including self)14432026/10/06 08:59:18 INFO Uploading w8yw37pmqsqml08sa8ql79cf6rax34zy-test-file-0.txt (160B)14442026/10/06 08:59:18 INFO Uploading pdxdvipd6rd49l6npdr6hsiysnqca8mw-test-file-2.txt (160B)14452026/10/06 08:59:18 INFO Uploading bix02g0wb18ymwm3nkifycb3zywnfady-test-file-1.txt (160B)14462026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads14472026/10/06 08:59:18 WARN Failed to register uploaded object key=w8yw37pmqsqml08sa8ql79cf6rax34zy.ls error="server returned 404: 404 page not found\n"14482026/10/06 08:59:18 WARN Failed to register uploaded object key=pdxdvipd6rd49l6npdr6hsiysnqca8mw.ls error="server returned 404: 404 page not found\n"14492026/10/06 08:59:18 WARN Failed to register uploaded object key=bix02g0wb18ymwm3nkifycb3zywnfady.ls error="server returned 404: 404 page not found\n"14502026/10/06 08:59:18 INFO Vacuumed table table=closures14512026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14522026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14532026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14542026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14552026/10/06 08:59:18 INFO Signed narinfos id=1 count=314562026/10/06 08:59:18 INFO Uploading 3 narinfos14572026/10/06 08:59:18 INFO Vacuumed table table=objects14582026/10/06 08:59:18 WARN Failed to register uploaded object key=bix02g0wb18ymwm3nkifycb3zywnfady.narinfo error="server returned 404: 404 page not found\n"14592026/10/06 08:59:18 WARN Failed to register uploaded object key=w8yw37pmqsqml08sa8ql79cf6rax34zy.narinfo error="server returned 404: 404 page not found\n"14602026/10/06 08:59:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures14612026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete14622026/10/06 08:59:18 WARN Failed to register uploaded object key=pdxdvipd6rd49l6npdr6hsiysnqca8mw.narinfo error="server returned 404: 404 page not found\n"14632026/10/06 08:59:18 INFO Garbage collection started1464=== RUN TestService_RequireScope_OIDC/builder_may_write1465=== PAUSE TestService_RequireScope_OIDC/builder_may_write1466=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1467=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1468=== RUN TestService_RequireScope_OIDC/ops_may_admin1469=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1470=== RUN TestService_RequireScope_OIDC/ops_may_not_write1471=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1472=== RUN TestService_RequireScope_OIDC/reader_may_not_write1473=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1474=== RUN TestService_RequireScope_OIDC/static_token_may_admin1475=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1476=== RUN TestService_RequireScope_OIDC/static_token_may_write1477=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1478=== RUN TestService_RequireScope_OIDC/reader_may_read1479=== PAUSE TestService_RequireScope_OIDC/reader_may_read1480=== RUN TestService_RequireScope_OIDC/writer_implies_read1481=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1482=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1483=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1484=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1485=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1486=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1487=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1488=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1489=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1490=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1491=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1492=== CONT TestPushDedupSurvivesConcurrentGC14932026/10/06 08:59:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001494--- PASS: TestService_createPendingClosureHandler (1.17s)1495=== CONT TestLeadEndsOnShutdown14962026/10/06 08:59:18 INFO All 1 paths already cached1497=== NAME TestClientIntegration1498 client_integration_test.go:312: Retrieved narinfo from S3:1499 StorePath: /build/TestClientIntegration2757966493/002/store/4jb4d9h7bjd8fdnqa6id3ylixv3b2kpj-test-file.txt1500 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1501 Compression: zstd1502 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11503 NarSize: 1521504 References: 1505 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115062026/10/06 08:59:18 INFO Upload complete. (80ms)1507=== NAME TestClientMultipleUploads1508 client_integration_test.go:369: Uploaded 3 paths in 111.658825ms1509=== NAME TestClientIntegration1510 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1511 client_integration_test.go:313: Decompressed .ls content (64 bytes):1512 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1513 client_integration_test.go:316: Testing garbage collection...15142026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=015152026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=01516--- PASS: TestClientMultipleUploads (0.69s)1517=== CONT TestGCMetrics15182026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period15192026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period15202026/10/06 08:59:18 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15212026/10/06 08:59:18 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1522--- PASS: TestFailedS3DeleteKeepsTombstone (0.45s)1523=== CONT TestGCBugBareHashReferences1524=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1525=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1526=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1527=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1528=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1529=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1530=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1531=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1532=== CONT TestLeadIncumbentAnnouncesAtOnce15332026/10/06 08:59:18 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=015342026/10/06 08:59:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures15352026/10/06 08:59:18 INFO Garbage collection started15362026/10/06 08:59:18 INFO Vacuumed table table=pending_closures15372026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=015382026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period15392026/10/06 08:59:18 INFO Vacuumed table table=pending_objects15402026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads15412026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures15422026/10/06 08:59:18 INFO Vacuumed table table=closures1543--- PASS: TestPushWaitsForSweepHoldingRow (1.04s)1544=== CONT TestLeadElectsOneAndHandsOver15452026/10/06 08:59:18 INFO Vacuumed table table=objects15462026/10/06 08:59:18 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=015472026/10/06 08:59:18 INFO Vacuumed table table=pending_closures15482026/10/06 08:59:18 INFO Vacuumed table table=pending_objects15492026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads1550--- PASS: TestService_ReadAuthMiddleware (0.27s)1551=== CONT TestProxyWriteTimeout/narinfo1552=== CONT TestProxyWriteTimeout/unknown_size1553=== CONT TestProxyWriteTimeout/1_GiB_nar1554=== CONT TestProxyWriteTimeout/10_GiB_nar1555--- PASS: TestProxyWriteTimeout (0.08s)1556 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1557 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1558 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1559 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1560=== CONT TestPendingClosureWriteTimeout/empty1561=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15622026/10/06 08:59:18 INFO Vacuumed table table=closures15632026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes15642026/10/06 08:59:18 INFO Vacuumed table table=objects15652026/10/06 08:59:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15662026/10/06 08:59:18 INFO Uploading hxfibyaapcbdnx2q9rc6j3m7h7080naq-ca-test (144B)15672026/10/06 08:59:18 WARN Failed to register uploaded object key=log/pgi7ip5wdlk8saqskwg07w6gyjdkpz8k-ca-test.drv error="server returned 404: 404 page not found\n"15682026/10/06 08:59:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15692026/10/06 08:59:18 WARN Failed to register uploaded object key=hxfibyaapcbdnx2q9rc6j3m7h7080naq.ls error="server returned 404: 404 page not found\n"15702026/10/06 08:59:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15712026/10/06 08:59:18 INFO Signed narinfos id=1 count=115722026/10/06 08:59:18 INFO Uploading 1 narinfos15732026/10/06 08:59:18 INFO Received complete push request method=POST path=/api/pushes/1/complete15742026/10/06 08:59:18 WARN Failed to register uploaded object key=hxfibyaapcbdnx2q9rc6j3m7h7080naq.narinfo error="server returned 404: 404 page not found\n"15752026/10/06 08:59:18 INFO Upload complete. (121ms)1576=== NAME TestClientCADerivations1577 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4254186630/001/store/hxfibyaapcbdnx2q9rc6j3m7h7080naq-ca-test1578 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1579 Compression: zstd1580 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1581 NarSize: 1441582 References: 1583 Deriver: /build/TestClientCADerivations4254186630/001/store/pgi7ip5wdlk8saqskwg07w6gyjdkpz8k-ca-test.drv1584 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1585 client_ca_test.go:185: Checking for realisation files in S3...1586 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1587 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15882026/10/06 08:59:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15892026/10/06 08:59:18 WARN mTLS auth: bound subjects configured but subject DN unavailable15902026/10/06 08:59:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1591--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.30s)1592=== CONT TestPendingClosureWriteTimeout/670k_objects1593=== CONT TestPendingClosureWriteTimeout/400_objects1594=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15952026/10/06 08:59:18 INFO Received uploads request method=POST path=/1596=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15972026/10/06 08:59:18 INFO Received complete multipart upload request method=POST path=/1598=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15992026/10/06 08:59:18 INFO Received uploads request method=POST path=/1600=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16012026/10/06 08:59:18 INFO Received request for more parts method=POST path=/1602--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1603 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1604 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1605 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1606 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1607=== CONT TestIsValidUploadKey/narinfo1608=== CONT TestIsValidUploadKey/empty_key1609=== CONT TestIsValidUploadKey/absolute1610=== CONT TestIsValidUploadKey/traversal_nar1611=== CONT TestIsValidUploadKey/traversal1612=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1613=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1614=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1615=== CONT TestIsValidUploadKey/index.html1616=== CONT TestIsValidUploadKey/nix-cache-info1617=== CONT TestIsValidUploadKey/realisation_plus_in_output1618=== CONT TestIsValidUploadKey/realisation1619=== CONT TestIsValidUploadKey/build_log_equals1620=== CONT TestIsValidUploadKey/build_log_question_mark1621=== CONT TestIsValidUploadKey/build_log_plus_in_name1622=== CONT TestIsValidUploadKey/build_log_home-manager_file1623=== CONT TestIsValidUploadKey/build_log1624=== CONT TestIsValidUploadKey/listing1625=== CONT TestIsValidUploadKey/nar_plain1626=== CONT TestIsValidUploadKey/nar_xz1627=== CONT TestIsValidUploadKey/nar_zst1628=== CONT TestIsValidUploadKey/unknown_type1629--- PASS: TestIsValidUploadKey (0.08s)1630 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1631 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1632 --- PASS: TestIsValidUploadKey/absolute (0.00s)1633 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1634 --- PASS: TestIsValidUploadKey/traversal (0.00s)1635 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1636 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1637 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1638 --- PASS: TestIsValidUploadKey/index.html (0.00s)1639 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1640 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1641 --- PASS: TestIsValidUploadKey/realisation (0.00s)1642 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1643 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1644 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1645 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1646 --- PASS: TestIsValidUploadKey/build_log (0.00s)1647 --- PASS: TestIsValidUploadKey/listing (0.00s)1648 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1649 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1650 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1651 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1652=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16532026/10/06 08:59:18 INFO Received request for more parts method=POST path=/16542026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=016552026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period16562026/10/06 08:59:18 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=016572026/10/06 08:59:18 INFO Vacuumed table table=pending_closures16582026/10/06 08:59:18 INFO Vacuumed table table=pending_objects16592026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads16602026/10/06 08:59:18 INFO Vacuumed table table=closures16612026/10/06 08:59:18 INFO Vacuumed table table=objects1662--- PASS: TestGCSweepDeliversEachKeyOnce (0.35s)1663=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16642026/10/06 08:59:18 INFO Received complete multipart upload request method=POST path=/16652026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures1666--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.31s)1667=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16682026/10/06 08:59:18 INFO Received uploads request method=POST path=/1669=== CONT TestIsValidCachePath/narinfo1670=== CONT TestIsValidCachePath/traversal_in_middle1671=== CONT TestIsValidCachePath/traversal_parent1672=== CONT TestIsValidCachePath/index.html1673=== CONT TestIsValidCachePath/nix-cache-info1674=== CONT TestIsValidCachePath/realisation1675=== CONT TestIsValidCachePath/log1676=== CONT TestIsValidCachePath/ls1677=== CONT TestIsValidCachePath/nar_uncompressed1678=== CONT TestIsValidCachePath/nar_bz21679=== CONT TestIsValidCachePath/nar_xz1680=== CONT TestIsValidCachePath/nar_zst1681=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1682=== CONT TestIsValidCachePath/invalid_char_e1683=== CONT TestIsValidCachePath/leading_slash1684=== CONT TestIsValidCachePath/empty1685=== CONT TestIsValidCachePath/random_path1686=== CONT TestIsValidCachePath/invalid_char_u1687=== CONT TestIsValidCachePath/short_hash1688=== CONT TestIsValidCachePath/wrong_extension1689--- PASS: TestIsValidCachePath (0.00s)1690 --- PASS: TestIsValidCachePath/narinfo (0.00s)1691 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1692 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1693 --- PASS: TestIsValidCachePath/index.html (0.00s)1694 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1695 --- PASS: TestIsValidCachePath/realisation (0.00s)1696 --- PASS: TestIsValidCachePath/log (0.00s)1697 --- PASS: TestIsValidCachePath/ls (0.00s)1698 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1699 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1700 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1701 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1702 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1703 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1704 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1705 --- PASS: TestIsValidCachePath/empty (0.00s)1706 --- PASS: TestIsValidCachePath/random_path (0.00s)1707 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1708 --- PASS: TestIsValidCachePath/short_hash (0.00s)1709 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1710=== CONT TestParseSingleRange/none1711=== CONT TestParseSingleRange/open-ended1712=== CONT TestParseSingleRange/closed1713=== CONT TestParseSingleRange/malformed_end_before_start1714=== CONT TestParseSingleRange/malformed_both_empty1715=== CONT TestParseSingleRange/malformed_no_dash1716=== CONT TestParseSingleRange/multi-range_ignored1717=== CONT TestParseSingleRange/unknown_unit1718=== CONT TestParseSingleRange/start_past_EOF1719=== CONT TestParseSingleRange/end_clamped_to_size1720=== CONT TestParseSingleRange/single_byte1721=== CONT TestParseSingleRange/suffix_exceeds_size1722=== CONT TestParseSingleRange/suffix1723=== CONT TestParseSingleRange/start_far_past_EOF1724--- PASS: TestParseSingleRange (0.00s)1725 --- PASS: TestParseSingleRange/none (0.00s)1726 --- PASS: TestParseSingleRange/open-ended (0.00s)1727 --- PASS: TestParseSingleRange/closed (0.00s)1728 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1729 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1730 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1731 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1732 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1733 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1734 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1735 --- PASS: TestParseSingleRange/single_byte (0.00s)1736 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1737 --- PASS: TestParseSingleRange/suffix (0.00s)1738 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1739=== CONT TestPush_RejectsBadRequests/no_roots17402026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes1741=== CONT TestPush_RejectsBadRequests/bad_root17422026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes1743=== CONT TestPush_RejectsBadRequests/root_not_in_objects17442026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes1745=== CONT TestPush_RejectsBadRequests/no_objects17462026/10/06 08:59:18 INFO Received push request method=POST path=/api/pushes1747=== CONT TestServerTLSConfig/no_client_CA1748=== CONT TestServerTLSConfig/not_a_PEM_file1749--- PASS: TestPush_RejectsBadRequests (0.56s)1750 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1751 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1752 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1753 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1754=== CONT TestServerTLSConfig/missing_CA_file1755--- PASS: TestServerTLSConfig (0.00s)1756 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1757 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1758 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1759=== CONT TestGCEndsOnShutdown/before_the_run1760--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.33s)1761=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17622026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures1763=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17642026/10/06 08:59:18 INFO Aborted multipart uploads count=0 kept=017652026/10/06 08:59:18 WARN Force mode enabled - objects will be deleted immediately without grace period1766=== NAME TestClientCADerivations1767 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features17682026/10/06 08:59:18 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=01769 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1770 error: binary cache 's3://bucket62?endpoint=http://localhost:37961®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4254186630/001/store'1771 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11772--- PASS: TestClientCADerivations (0.86s)17732026/10/06 08:59:18 INFO Vacuumed table table=pending_closures1774=== CONT TestResolveDBConnectionString/flag_wins17752026/10/06 08:59:18 INFO Received uploads request method=POST path=/api/pending_closures1776=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1777=== CONT TestResolveDBConnectionString/nothing_configured1778=== CONT TestResolveDBConnectionString/missing_file_is_an_error1779=== CONT TestResolveDBConnectionString/file_when_flag_empty1780=== CONT TestClientErrorHandling/InvalidStorePath17812026/10/06 08:59:18 INFO Vacuumed table table=pending_objects1782--- PASS: TestResolveDBConnectionString (0.00s)1783 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1784 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1785 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1786 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1787 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17882026/10/06 08:59:18 INFO Vacuumed table table=multipart_uploads17892026/10/06 08:59:18 INFO Vacuumed table table=closures17902026/10/06 08:59:18 INFO Vacuumed table table=objects1791--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.32s)1792=== CONT TestClientErrorHandling/ServerNotAvailable1793--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.47s)1794=== CONT TestClientErrorHandling/InvalidAuthToken1795--- PASS: TestGCSweepSkipsPendingObjects (0.39s)1796=== CONT TestCacheConfigHandler/full_config,_no_issuer1797=== CONT TestCacheConfigHandler/no_signing_keys1798=== CONT TestCacheConfigHandler/no_cache_url_configured1799=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1800--- PASS: TestCacheConfigHandler (0.00s)1801 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1802 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1803 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1804 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1805=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18062026/10/06 08:59:18 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"1807--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.34s)1808=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18092026/10/06 08:59:19 INFO Received cleanup request method=DELETE path=/api/pending_closures18102026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=018112026/10/06 08:59:19 INFO Received uploads request method=POST path=/api/pending_closures18122026/10/06 08:59:19 INFO Received cleanup request method=DELETE path=/api/pending_closures18132026/10/06 08:59:19 INFO Aborted multipart uploads count=1 kept=018142026/10/06 08:59:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18152026-10-06 08:59:19.069 UTC [1715] ERROR: Closure does not exist: id=118162026-10-06 08:59:19.069 UTC [1715] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE18172026-10-06 08:59:19.069 UTC [1715] STATEMENT: -- name: CommitPendingClosure :exec1818 SELECT commit_pending_closure($1::bigint)1819 1820--- PASS: TestService_cleanupPendingClosuresHandler (0.43s)1821=== CONT TestService_RequireScope_OIDC/builder_may_write1822=== CONT TestService_RequireScope_OIDC/reader_may_read1823=== CONT TestService_RequireScope_OIDC/static_token_may_write1824=== CONT TestService_RequireScope_OIDC/static_token_may_admin1825=== CONT TestService_RequireScope_OIDC/reader_may_not_write1826=== CONT TestService_RequireScope_OIDC/ops_may_not_write1827=== CONT TestService_RequireScope_OIDC/ops_may_admin1828=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1829=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18302026/10/06 08:59:19 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]1831=== CONT TestService_RequireScope_OIDC/writer_implies_read1832=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1833=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1834=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1835=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1836=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1837--- PASS: TestService_RequireScope_OIDC (0.29s)1838 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1842 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1843 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1844 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1845 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1846 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1847 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1848 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1849 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1850 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1851 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1852=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18532026/10/06 08:59:19 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]1854=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1855=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18562026/10/06 08:59:19 WARN Authentication failed token_preview=eyJhbGciOi...xx1iL2Q6MQ 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.28s)1858 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1859 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1860 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1861 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18622026/10/06 08:59:19 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/present18632026/10/06 08:59:19 INFO lead: acquired remote=192.0.2.1:123418642026/10/06 08:59:19 INFO Received uploads request method=POST path=/api/pending_closures18652026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=018662026/10/06 08:59:19 WARN Force mode enabled - objects will be deleted immediately without grace period18672026/10/06 08:59:19 INFO lead: acquired remote=192.0.2.1:123418682026/10/06 08:59:19 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=018692026/10/06 08:59:19 INFO lead: released remote=192.0.2.1:12341870--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.44s)18712026/10/06 08:59:19 INFO Vacuumed table table=pending_closures18722026/10/06 08:59:19 INFO Vacuumed table table=pending_objects18732026/10/06 08:59:19 INFO Vacuumed table table=multipart_uploads18742026/10/06 08:59:19 INFO Vacuumed table table=closures18752026/10/06 08:59:19 INFO Vacuumed table table=objects1876--- PASS: TestGCMetrics (0.47s)18772026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=018782026/10/06 08:59:19 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=018792026/10/06 08:59:19 INFO Vacuumed table table=pending_closures18802026/10/06 08:59:19 INFO Vacuumed table table=pending_objects18812026/10/06 08:59:19 INFO Vacuumed table table=multipart_uploads18822026/10/06 08:59:19 INFO Vacuumed table table=closures18832026/10/06 08:59:19 INFO Vacuumed table table=objects18842026/10/06 08:59:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.447285ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18852026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=018862026/10/06 08:59:19 WARN Force mode enabled - objects will be deleted immediately without grace period18872026/10/06 08:59:19 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=018882026/10/06 08:59:19 INFO Vacuumed table table=pending_closures18892026/10/06 08:59:19 INFO Vacuumed table table=pending_objects18902026/10/06 08:59:19 INFO Vacuumed table table=multipart_uploads18912026/10/06 08:59:19 INFO Vacuumed table table=closures18922026/10/06 08:59:19 INFO Vacuumed table table=objects1893--- PASS: TestPushDedupSurvivesConcurrentGC (0.52s)18942026/10/06 08:59:19 INFO lead: acquired remote=192.0.2.1:123418952026/10/06 08:59:19 INFO Received uploads request method=POST path=/api/pending_closures18962026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=018972026/10/06 08:59:19 WARN Force mode enabled - objects will be deleted immediately without grace period18982026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=018992026/10/06 08:59:19 WARN Force mode enabled - objects will be deleted immediately without grace period19002026/10/06 08:59:19 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37961/bucket88/?delete=\": context canceled"1901--- PASS: TestGCEndsOnShutdown (0.00s)1902 --- PASS: TestGCEndsOnShutdown/before_the_run (0.37s)1903 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.42s)1904 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.38s)1905=== NAME TestOrphanedObjectsGCStressTest1906 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1907 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19082026/10/06 08:59:19 INFO Received uploads request method=POST path=/api/pending_closures19092026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=01910--- PASS: TestGCBugBareHashReferences (0.69s)19112026/10/06 08:59:19 WARN Force mode enabled - objects will be deleted immediately without grace period19122026/10/06 08:59:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.782793ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19132026/10/06 08:59:19 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=019142026/10/06 08:59:19 INFO Vacuumed table table=pending_closures19152026/10/06 08:59:19 INFO Vacuumed table table=pending_objects19162026/10/06 08:59:19 INFO Vacuumed table table=multipart_uploads19172026/10/06 08:59:19 INFO Vacuumed table table=closures19182026/10/06 08:59:19 INFO Vacuumed table table=objects19192026/10/06 08:59:19 INFO Received uploads request method=POST path=/api/pending_closures19202026/10/06 08:59:19 INFO Aborted multipart uploads count=0 kept=019212026/10/06 08:59:19 WARN Force mode enabled - objects will be deleted immediately without grace period19222026/10/06 08:59:19 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=019232026/10/06 08:59:19 INFO Vacuumed table table=pending_closures19242026/10/06 08:59:19 INFO Vacuumed table table=pending_objects19252026/10/06 08:59:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19262026/10/06 08:59:19 INFO Vacuumed table table=multipart_uploads19272026/10/06 08:59:19 INFO Vacuumed table table=closures19282026/10/06 08:59:19 INFO Vacuumed table table=objects1929--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1930 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.43s)1931 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.49s)19322026/10/06 08:59:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1933--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1934 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1935 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1936 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.75s)1937=== NAME TestOrphanedObjectsGCStressTest1938 orphaned_objects_gc_test.go:509: Stress test completed successfully:1939 orphaned_objects_gc_test.go:510: - Active objects preserved: 201940 orphaned_objects_gc_test.go:511: - Objects deleted: 2101941 orphaned_objects_gc_test.go:512: - Total GC'd: 2101942--- PASS: TestOrphanedObjectsGCStressTest (2.70s)19432026/10/06 08:59:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=728.478736ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1944--- PASS: TestPendingClosureWriteTimeout (0.08s)1945 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1946 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1947 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1948 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.25s)19492026/10/06 08:59:20 INFO lead: released remote=192.0.2.1:12341950--- PASS: TestLeadEndsOnShutdown (1.47s)19512026/10/06 08:59:20 INFO lead: released remote=192.0.2.1:123419522026/10/06 08:59:20 INFO lead: acquired remote=192.0.2.1:123419532026/10/06 08:59:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.608198976s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19542026/10/06 08:59:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019552026/10/06 08:59:20 INFO Received create pin request method=POST path=/api/pins/myapp19562026/10/06 08:59:20 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC838844497/001/store/k2wyrpinkjcngr7spj6xqbpfp7w4v3ba-pinned-file.txt narinfo_key=k2wyrpinkjcngr7spj6xqbpfp7w4v3ba.narinfo19572026/10/06 08:59:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures19582026/10/06 08:59:20 INFO Garbage collection started19592026/10/06 08:59:20 INFO Aborted multipart uploads count=0 kept=019602026/10/06 08:59:20 WARN Force mode enabled - objects will be deleted immediately without grace period19612026/10/06 08:59:20 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=019622026/10/06 08:59:20 INFO Vacuumed table table=pending_closures19632026/10/06 08:59:20 INFO Vacuumed table table=pending_objects19642026/10/06 08:59:20 INFO Vacuumed table table=multipart_uploads19652026/10/06 08:59:20 INFO Vacuumed table table=closures19662026/10/06 08:59:20 INFO Vacuumed table table=objects19672026/10/06 08:59:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01968=== NAME TestClientIntegration1969 client_integration_test.go:323: Objects in database after GC:1970 client_integration_test.go:323: Successfully deleted all objects with GC --force1971--- PASS: TestClientIntegration (2.71s)19722026/10/06 08:59:21 WARN Rate limiter enabled after throttle name=s3-test rate=519732026/10/06 08:59:21 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1974=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1975 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101976 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001977--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.70s)19782026/10/06 08:59:21 INFO lead: released remote=192.0.2.1:12341979--- PASS: TestLeadElectsOneAndHandsOver (2.80s)1980--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.06s)19812026/10/06 08:59:22 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-config19822026/10/06 08:59:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.93516ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19832026/10/06 08:59:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.263963ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1984=== NAME TestPinProtectsFromGC1985 client_integration_test.go:840: Pin successfully protected closure from garbage collection1986--- PASS: TestPinProtectsFromGC (4.89s)1987--- PASS: TestConnectWaitsForAPeerMigration (5.17s)19882026/10/06 08:59:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.682415ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19892026/10/06 08:59:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.651841686s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19902026/10/06 08:59:23 INFO Aborted multipart uploads count=1 kept=019912026/10/06 08:59:23 INFO Received cleanup request method=DELETE path=/api/pending_closures19922026/10/06 08:59:23 INFO Aborted multipart uploads count=1 kept=01993--- PASS: TestPendingCleanupUsesOneCutoff (6.65s)19942026/10/06 08:59:25 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"19952026/10/06 08:59:25 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-config19962026/10/06 08:59:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.694276ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19972026/10/06 08:59:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.252923ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19982026/10/06 08:59:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.863258ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19992026/10/06 08:59:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.617968829s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20002026/10/06 08:59:28 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_closures20012026/10/06 08:59:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.635625ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20022026/10/06 08:59:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=398.093591ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20032026/10/06 08:59:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=814.375231ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20042026/10/06 08:59:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74685063s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2005--- PASS: TestClientErrorHandling (0.00s)2006 --- PASS: TestClientErrorHandling/InvalidStorePath (0.41s)2007 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.51s)2008 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.64s)2009PASS20102026-10-06 08:59:31.942 UTC [127] LOG: received smart shutdown request20112026-10-06 08:59:31.947 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 120122026-10-06 08:59:31.958 UTC [132] LOG: shutting down20132026-10-06 08:59:31.959 UTC [132] LOG: checkpoint starting: shutdown immediate20142026-10-06 08:59:32.570 UTC [132] LOG: checkpoint complete: wrote 10937 buffers (66.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.292 s, sync=0.278 s, total=0.612 s; sync files=31336, longest=0.033 s, average=0.001 s; distance=433050 kB, estimate=433050 kB; lsn=0/1BE4C6E0, redo lsn=0/1BE4C6E020152026-10-06 08:59:32.652 UTC [127] LOG: database system is shut down2016Running OIDC tests...2017=== RUN TestAudienceForIssuer2018=== PAUSE TestAudienceForIssuer2019=== RUN TestGlobMatch2020=== PAUSE TestGlobMatch2021=== RUN TestValidateToken_ValidToken2022=== PAUSE TestValidateToken_ValidToken2023=== RUN TestValidateToken_WrongAudience2024=== PAUSE TestValidateToken_WrongAudience2025=== RUN TestValidateToken_Expired2026=== PAUSE TestValidateToken_Expired2027=== RUN TestValidateToken_BoundClaimsMismatch2028=== PAUSE TestValidateToken_BoundClaimsMismatch2029=== RUN TestValidateToken_BoundSubjectMismatch2030=== PAUSE TestValidateToken_BoundSubjectMismatch2031=== RUN TestValidateToken_MultipleProviders2032=== PAUSE TestValidateToken_MultipleProviders2033=== RUN TestValidateToken_NoMatchingProvider2034=== PAUSE TestValidateToken_NoMatchingProvider2035=== RUN TestValidateToken_KubernetesServiceAccount2036=== PAUSE TestValidateToken_KubernetesServiceAccount2037=== RUN TestNewValidator_KubernetesRequiresCA2038=== PAUSE TestNewValidator_KubernetesRequiresCA2039=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2040=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2041=== RUN TestPins_ReservedForMatchingRule2042=== PAUSE TestPins_ReservedForMatchingRule2043=== RUN TestPins_TopLevelShorthand2044=== PAUSE TestPins_TopLevelShorthand2045=== RUN TestPins_ConfigValidation2046=== PAUSE TestPins_ConfigValidation2047=== RUN TestScopes_LegacyProviderDefaultsToWrite2048=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2049=== RUN TestScopes_Rules2050=== PAUSE TestScopes_Rules2051=== RUN TestScopes_ConfigValidation2052=== PAUSE TestScopes_ConfigValidation2053=== CONT TestAudienceForIssuer2054=== CONT TestPins_ConfigValidation2055--- PASS: TestAudienceForIssuer (0.00s)2056=== CONT TestValidateToken_NoMatchingProvider2057=== CONT TestValidateToken_MultipleProviders2058=== CONT TestValidateToken_BoundSubjectMismatch2059=== CONT TestValidateToken_BoundClaimsMismatch2060=== CONT TestValidateToken_KubernetesServiceAccount2061--- PASS: TestPins_ConfigValidation (0.00s)2062=== CONT TestValidateToken_Expired2063=== CONT TestValidateToken_WrongAudience2064=== CONT TestValidateToken_ValidToken2065=== CONT TestPins_TopLevelShorthand2066=== CONT TestPins_ReservedForMatchingRule2067=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2068=== CONT TestGlobMatch2069=== RUN TestGlobMatch/foo_foo2070=== PAUSE TestGlobMatch/foo_foo2071=== RUN TestGlobMatch/foo_bar2072=== PAUSE TestGlobMatch/foo_bar2073=== RUN TestGlobMatch/*_2074=== CONT TestNewValidator_KubernetesRequiresCA2075=== CONT TestScopes_LegacyProviderDefaultsToWrite2076=== CONT TestScopes_ConfigValidation2077=== CONT TestScopes_Rules2078=== PAUSE TestGlobMatch/*_2079=== RUN TestGlobMatch/*_anything2080=== PAUSE TestGlobMatch/*_anything2081=== RUN TestGlobMatch/foo*_foo2082=== PAUSE TestGlobMatch/foo*_foo2083=== RUN TestGlobMatch/foo*_foobar2084=== PAUSE TestGlobMatch/foo*_foobar2085=== RUN TestGlobMatch/foo*_bar2086=== PAUSE TestGlobMatch/foo*_bar2087=== RUN TestGlobMatch/*bar_bar2088=== PAUSE TestGlobMatch/*bar_bar2089=== RUN TestGlobMatch/*bar_foobar2090=== PAUSE TestGlobMatch/*bar_foobar2091=== RUN TestGlobMatch/*bar_foo2092=== PAUSE TestGlobMatch/*bar_foo2093=== RUN TestGlobMatch/foo*bar_foobar2094=== PAUSE TestGlobMatch/foo*bar_foobar2095=== RUN TestGlobMatch/foo*bar_foo123bar2096=== PAUSE TestGlobMatch/foo*bar_foo123bar2097=== RUN TestGlobMatch/foo*bar_foobarbaz2098=== PAUSE TestGlobMatch/foo*bar_foobarbaz2099=== RUN TestGlobMatch/*/*_foo/bar2100=== PAUSE TestGlobMatch/*/*_foo/bar2101=== RUN TestGlobMatch/*/*_foo2102=== PAUSE TestGlobMatch/*/*_foo2103=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2104=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2105=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02106=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02107=== RUN TestGlobMatch/refs/*/main_refs/heads/main2108=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2109=== RUN TestGlobMatch/fo?_foo2110=== PAUSE TestGlobMatch/fo?_foo2111=== RUN TestGlobMatch/fo?_fo2112=== PAUSE TestGlobMatch/fo?_fo2113=== RUN TestGlobMatch/fo?_fooo2114=== PAUSE TestGlobMatch/fo?_fooo2115=== RUN TestGlobMatch/?oo_foo2116=== PAUSE TestGlobMatch/?oo_foo2117=== RUN TestGlobMatch/?oo_boo2118=== PAUSE TestGlobMatch/?oo_boo2119=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2120=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2121=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2122=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2123=== CONT TestGlobMatch/foo_foo2124=== CONT TestGlobMatch/foo*bar_foobarbaz2125=== CONT TestGlobMatch/foo*bar_foo123bar2126=== CONT TestGlobMatch/foo*bar_foobar2127=== CONT TestGlobMatch/*bar_foo2128=== CONT TestGlobMatch/*bar_foobar2129=== CONT TestGlobMatch/*bar_bar2130=== CONT TestGlobMatch/foo*_bar2131=== CONT TestGlobMatch/foo*_foobar2132=== CONT TestGlobMatch/foo*_foo2133=== CONT TestGlobMatch/*_anything2134=== CONT TestGlobMatch/*_2135=== CONT TestGlobMatch/foo_bar2136=== CONT TestGlobMatch/fo?_fo2137=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2138=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2139=== CONT TestGlobMatch/?oo_boo2140=== CONT TestGlobMatch/?oo_foo2141=== CONT TestGlobMatch/fo?_fooo2142=== CONT TestGlobMatch/refs/*/main_refs/heads/main2143=== CONT TestGlobMatch/*/*_foo/bar2144=== CONT TestGlobMatch/fo?_foo2145=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2146=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02147=== CONT TestGlobMatch/*/*_foo2148--- PASS: TestGlobMatch (0.00s)2149 --- PASS: TestGlobMatch/foo_foo (0.00s)2150 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2151 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2152 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2153 --- PASS: TestGlobMatch/*bar_foo (0.00s)2154 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2155 --- PASS: TestGlobMatch/*bar_bar (0.00s)2156 --- PASS: TestGlobMatch/foo*_bar (0.00s)2157 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2158 --- PASS: TestGlobMatch/foo*_foo (0.00s)2159 --- PASS: TestGlobMatch/*_anything (0.00s)2160 --- PASS: TestGlobMatch/*_ (0.00s)2161 --- PASS: TestGlobMatch/foo_bar (0.00s)2162 --- PASS: TestGlobMatch/fo?_fo (0.00s)2163 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2164 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2165 --- PASS: TestGlobMatch/?oo_boo (0.00s)2166 --- PASS: TestGlobMatch/?oo_foo (0.00s)2167 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2168 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2169 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2170 --- PASS: TestGlobMatch/fo?_foo (0.00s)2171 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2172 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2173 --- PASS: TestGlobMatch/*/*_foo (0.00s)2174--- PASS: TestScopes_ConfigValidation (0.00s)21752026/10/06 08:59:34 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4674321762026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43857/oidc2177--- PASS: TestValidateToken_WrongAudience (0.03s)2178--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)21792026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37209/oidc2180--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)21812026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35325/oidc2182--- PASS: TestValidateToken_Expired (0.05s)21832026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41027/oidc21842026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42809/oidc2185--- PASS: TestPins_TopLevelShorthand (0.06s)21862026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45035/oidc2187--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2188--- PASS: TestValidateToken_ValidToken (0.06s)21892026/10/06 08:59:34 http: TLS handshake error from 127.0.0.1:43216: remote error: tls: bad certificate2190--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)21912026/10/06 08:59:34 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321922026/10/06 08:59:34 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35571/oidc21932026/10/06 08:59:34 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34281/oidc2194--- PASS: TestValidateToken_MultipleProviders (0.08s)2195--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)21962026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38659/oidc2197--- PASS: TestPins_ReservedForMatchingRule (0.09s)21982026/10/06 08:59:34 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33543/oidc2199--- PASS: TestValidateToken_NoMatchingProvider (0.10s)22002026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35043/oidc2201--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.13s)22022026/10/06 08:59:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34807/oidc2203--- PASS: TestScopes_Rules (0.25s)2204PASS2205Running hook tests...2206=== RUN TestSendPathsEmpty2207=== PAUSE TestSendPathsEmpty2208=== RUN TestQueueEnqueueAndFetch2209=== PAUSE TestQueueEnqueueAndFetch2210=== RUN TestQueueDeduplication2211=== PAUSE TestQueueDeduplication2212=== RUN TestQueueRemove2213=== PAUSE TestQueueRemove2214=== RUN TestQueueFetchBatchLimit2215=== PAUSE TestQueueFetchBatchLimit2216=== RUN TestQueueRetryMovesToBack2217=== PAUSE TestQueueRetryMovesToBack2218=== RUN TestQueueFetchRemoveLifecycle2219=== PAUSE TestQueueFetchRemoveLifecycle2220=== RUN TestQueueConcurrentWriters2221=== PAUSE TestQueueConcurrentWriters2222=== RUN TestQueueRemoveLargeClosure2223=== PAUSE TestQueueRemoveLargeClosure2224=== RUN TestServerClientIntegration2225=== PAUSE TestServerClientIntegration2226=== RUN TestServerQueueError2227=== PAUSE TestServerQueueError2228=== RUN TestGetListenerSocketActivation2229 server_test.go:210: === RUN TestGetListenerSocketActivation2230 --- PASS: TestGetListenerSocketActivation (0.00s)2231 PASS2232 2233--- PASS: TestGetListenerSocketActivation (0.01s)2234=== RUN TestDrainIsolatesPoisonPath2235=== PAUSE TestDrainIsolatesPoisonPath2236=== RUN TestRunNotBlockedByPoisonHead2237=== PAUSE TestRunNotBlockedByPoisonHead2238=== RUN TestDrainGivesUpWhenServerDown2239=== PAUSE TestDrainGivesUpWhenServerDown2240=== RUN TestFailedPathPrunedByLaterClosure2241=== PAUSE TestFailedPathPrunedByLaterClosure2242=== RUN TestWorkerUploadsAndRemoves2243=== PAUSE TestWorkerUploadsAndRemoves2244=== RUN TestWorkerSkipsGCdPaths2245=== PAUSE TestWorkerSkipsGCdPaths2246=== RUN TestWorkerPrunesClosureDeps2247=== PAUSE TestWorkerPrunesClosureDeps2248=== RUN TestDrainTimeout2249=== PAUSE TestDrainTimeout2250=== CONT TestSendPathsEmpty2251=== CONT TestServerQueueError2252--- PASS: TestSendPathsEmpty (0.00s)2253=== CONT TestQueueFetchBatchLimit2254=== CONT TestQueueRemove2255=== CONT TestQueueDeduplication22562026/10/06 08:59:34 ERROR Failed to queue paths error="permission denied" count=12257=== CONT TestQueueEnqueueAndFetch2258=== CONT TestQueueRemoveLargeClosure2259--- PASS: TestServerQueueError (0.00s)2260=== CONT TestServerClientIntegration2261=== CONT TestQueueConcurrentWriters2262=== CONT TestDrainGivesUpWhenServerDown2263=== CONT TestFailedPathPrunedByLaterClosure2264=== CONT TestRunNotBlockedByPoisonHead2265=== CONT TestDrainIsolatesPoisonPath2266=== CONT TestWorkerPrunesClosureDeps2267=== CONT TestDrainTimeout2268=== CONT TestWorkerSkipsGCdPaths2269=== CONT TestQueueFetchRemoveLifecycle2270=== CONT TestQueueRetryMovesToBack2271=== CONT TestWorkerUploadsAndRemoves2272--- PASS: TestServerClientIntegration (0.00s)22732026/10/06 08:59:34 INFO Uploading batch count=422742026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=422752026/10/06 08:59:34 INFO Uploading batch count=122762026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=122772026/10/06 08:59:34 INFO Uploading batch count=222782026/10/06 08:59:34 INFO Upload queue status pending=222792026/10/06 08:59:34 INFO Upload queue status pending=322802026/10/06 08:59:34 INFO Uploading batch count=122812026/10/06 08:59:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2343960216/002/bbb22822026/10/06 08:59:34 INFO Uploading batch count=122832026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=12284--- PASS: TestQueueFetchBatchLimit (0.02s)2285--- PASS: TestQueueEnqueueAndFetch (0.02s)22862026/10/06 08:59:34 INFO Uploading batch count=122872026/10/06 08:59:34 INFO Upload queue status pending=22288--- PASS: TestQueueDeduplication (0.02s)22892026/10/06 08:59:34 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1861493182/002/nonexistent22902026/10/06 08:59:34 INFO Upload queue status pending=222912026/10/06 08:59:34 INFO Uploading batch count=222922026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=22293--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22942026/10/06 08:59:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3262199430/002/a22952026/10/06 08:59:34 INFO Uploading batch count=22296--- PASS: TestQueueRemove (0.02s)22972026/10/06 08:59:34 INFO Uploading batch count=12298--- PASS: TestQueueRetryMovesToBack (0.02s)22992026/10/06 08:59:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3262199430/002/b23002026/10/06 08:59:34 INFO Uploading batch count=123012026/10/06 08:59:34 INFO Uploading batch count=123022026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=123032026/10/06 08:59:34 INFO Uploading batch count=223042026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=223052026/10/06 08:59:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3262199430/002/c23062026/10/06 08:59:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3262199430/002/d23072026/10/06 08:59:34 INFO Uploading batch count=123082026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=12309--- PASS: TestWorkerPrunesClosureDeps (0.02s)23102026/10/06 08:59:34 INFO Uploading batch count=123112026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=12312--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23132026/10/06 08:59:34 INFO Uploading batch count=223142026/10/06 08:59:34 ERROR Upload failed error="upload failed" count=223152026/10/06 08:59:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3262199430/002/e23162026/10/06 08:59:34 ERROR Drain finished with paths left in queue remaining=123172026/10/06 08:59:34 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3262199430/002/f2318--- PASS: TestDrainIsolatesPoisonPath (0.02s)23192026/10/06 08:59:34 ERROR Drain finished with paths left in queue remaining=102320--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2321--- PASS: TestWorkerUploadsAndRemoves (0.04s)2322--- PASS: TestWorkerSkipsGCdPaths (0.04s)2323--- PASS: TestQueueRemoveLargeClosure (0.05s)23242026/10/06 08:59:35 ERROR Upload failed error="context deadline exceeded" count=223252026/10/06 08:59:35 ERROR Drain finished with paths left in queue remaining=42326--- PASS: TestDrainTimeout (0.22s)2327--- PASS: TestQueueConcurrentWriters (0.27s)23282026/10/06 08:59:35 INFO Uploading batch count=123292026/10/06 08:59:35 INFO Uploading batch count=123302026/10/06 08:59:35 INFO Uploading batch count=123312026/10/06 08:59:35 ERROR Upload failed error="upload failed" count=123322026/10/06 08:59:35 INFO Uploading batch count=123332026/10/06 08:59:35 ERROR Upload failed error="upload failed" count=123342026/10/06 08:59:35 INFO Uploading batch count=123352026/10/06 08:59:35 ERROR Upload failed error="upload failed" count=123362026/10/06 08:59:35 INFO Uploading batch count=123372026/10/06 08:59:35 ERROR Upload failed error="upload failed" count=123382026/10/06 08:59:35 ERROR Drain finished with paths left in queue remaining=12339--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2340PASS2341Running signing tests...2342=== RUN TestExternalSigner2343=== PAUSE TestExternalSigner2344=== RUN TestExternalSignerWrongPublicKey2345=== PAUSE TestExternalSignerWrongPublicKey2346=== RUN TestExternalSignerErrors2347=== PAUSE TestExternalSignerErrors2348=== RUN TestExternalSignerRestartsAfterCrash2349=== PAUSE TestExternalSignerRestartsAfterCrash2350=== RUN TestExternalSignerProgramErrorKeepsProcess2351=== PAUSE TestExternalSignerProgramErrorKeepsProcess2352=== RUN TestExternalSignerClose2353=== PAUSE TestExternalSignerClose2354=== RUN TestExternalSignerRejectsInvalidPublicKey2355=== PAUSE TestExternalSignerRejectsInvalidPublicKey2356=== RUN TestExternalSignerCancellation2357=== PAUSE TestExternalSignerCancellation2358=== RUN TestGenerateFingerprint2359=== PAUSE TestGenerateFingerprint2360=== RUN TestParseSigningKey2361=== PAUSE TestParseSigningKey2362=== RUN TestSign2363=== PAUSE TestSign2364=== RUN TestSignBatch2365=== PAUSE TestSignBatch2366=== RUN TestNilKeyPublicKey2367=== PAUSE TestNilKeyPublicKey2368=== RUN TestSignErrors2369=== PAUSE TestSignErrors2370=== CONT TestExternalSigner2371=== CONT TestExternalSignerCancellation2372=== CONT TestSignErrors2373=== CONT TestNilKeyPublicKey2374--- PASS: TestNilKeyPublicKey (0.00s)2375=== CONT TestSignBatch2376=== CONT TestSign2377=== CONT TestParseSigningKey2378=== RUN TestParseSigningKey/valid_32-byte_key2379=== PAUSE TestParseSigningKey/valid_32-byte_key2380=== CONT TestGenerateFingerprint2381=== CONT TestExternalSignerErrors2382=== CONT TestExternalSignerRestartsAfterCrash2383=== CONT TestExternalSignerWrongPublicKey2384=== CONT TestExternalSignerRejectsInvalidPublicKey2385=== CONT TestExternalSignerClose2386=== CONT TestExternalSignerProgramErrorKeepsProcess2387=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2388=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2389=== RUN TestGenerateFingerprint/basic_with_references2390=== PAUSE TestGenerateFingerprint/basic_with_references2391=== RUN TestExternalSignerErrors/invalid_JSON2392=== RUN TestParseSigningKey/no_colon2393=== PAUSE TestExternalSignerErrors/invalid_JSON2394=== RUN TestExternalSignerRejectsInvalidPublicKey/#002395--- PASS: TestSign (0.00s)2396--- PASS: TestSignBatch (0.00s)2397=== RUN TestGenerateFingerprint/no_references2398=== PAUSE TestGenerateFingerprint/no_references2399=== RUN TestSignErrors/nil_key2400=== PAUSE TestSignErrors/nil_key2401=== RUN TestExternalSignerErrors/wrong_shape2402=== PAUSE TestExternalSignerErrors/wrong_shape2403=== RUN TestExternalSignerErrors/missing_signatures2404=== PAUSE TestExternalSignerErrors/missing_signatures2405=== PAUSE TestParseSigningKey/no_colon2406=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002407=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2408=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2409=== RUN TestSignErrors/nil_narinfo2410=== RUN TestExternalSignerErrors/null_signatures2411=== PAUSE TestExternalSignerErrors/null_signatures2412=== RUN TestExternalSignerErrors/wrong_signatures_shape2413=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2414=== RUN TestExternalSignerErrors/missing_signature_name2415=== PAUSE TestExternalSignerErrors/missing_signature_name2416=== RUN TestExternalSignerErrors/invalid_signature_base642417=== RUN TestParseSigningKey/empty_name2418=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2419=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2420=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2421=== RUN TestGenerateFingerprint/invalid_nar_hash_length2422=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2423--- PASS: TestExternalSignerClose (0.00s)2424=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2425=== RUN TestGenerateFingerprint/invalid_store_path_prefix2426=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2427=== PAUSE TestSignErrors/nil_narinfo2428=== RUN TestSignErrors/invalid_narinfo2429=== PAUSE TestSignErrors/invalid_narinfo2430=== RUN TestSignErrors/canceled2431=== PAUSE TestSignErrors/canceled2432=== CONT TestSignErrors/nil_key2433--- PASS: TestExternalSignerWrongPublicKey (0.00s)2434=== PAUSE TestExternalSignerErrors/invalid_signature_base642435=== RUN TestExternalSignerErrors/exit_at_startup2436=== PAUSE TestExternalSignerErrors/exit_at_startup2437=== RUN TestExternalSignerErrors/exit_on_request2438=== CONT TestSignErrors/canceled2439=== PAUSE TestParseSigningKey/empty_name2440=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2441=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2442=== RUN TestGenerateFingerprint/invalid_reference_prefix2443=== CONT TestSignErrors/invalid_narinfo2444=== CONT TestSignErrors/nil_narinfo2445--- PASS: TestSignErrors (0.00s)2446 --- PASS: TestSignErrors/nil_key (0.00s)2447 --- PASS: TestSignErrors/canceled (0.00s)2448 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2449 --- PASS: TestSignErrors/nil_narinfo (0.00s)2450=== PAUSE TestExternalSignerErrors/exit_on_request2451=== RUN TestExternalSignerErrors/null2452=== PAUSE TestExternalSignerErrors/null2453=== RUN TestExternalSignerErrors/wrong_id2454=== PAUSE TestExternalSignerErrors/wrong_id2455=== RUN TestExternalSignerErrors/unrequested_key2456=== PAUSE TestExternalSignerErrors/unrequested_key2457=== RUN TestExternalSignerErrors/wrong_signature_name2458=== RUN TestParseSigningKey/invalid_base642459=== PAUSE TestParseSigningKey/invalid_base642460=== RUN TestParseSigningKey/wrong_length2461=== PAUSE TestParseSigningKey/wrong_length2462=== CONT TestParseSigningKey/valid_32-byte_key2463=== CONT TestParseSigningKey/invalid_base642464=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2465=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2466=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2467=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2468=== CONT TestExternalSignerRejectsInvalidPublicKey/#002469=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2470--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2471=== PAUSE TestExternalSignerErrors/wrong_signature_name2472=== CONT TestParseSigningKey/wrong_length2473=== CONT TestParseSigningKey/no_colon2474=== CONT TestParseSigningKey/empty_name2475=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2476--- PASS: TestParseSigningKey (0.00s)2477 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2478 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2479 --- PASS: TestParseSigningKey/wrong_length (0.00s)2480 --- PASS: TestParseSigningKey/no_colon (0.00s)2481 --- PASS: TestParseSigningKey/empty_name (0.00s)2482 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2483=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2484=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2485=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2486=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2487--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2488 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2489 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2490 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2491 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2492 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2493=== CONT TestGenerateFingerprint/basic_with_references2494=== CONT TestGenerateFingerprint/invalid_reference_prefix2495=== CONT TestGenerateFingerprint/invalid_store_path_prefix2496=== CONT TestGenerateFingerprint/invalid_nar_hash_length2497=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2498=== CONT TestGenerateFingerprint/no_references2499=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2500--- PASS: TestGenerateFingerprint (0.00s)2501 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2502 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2503 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2504 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2505 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2506 --- PASS: TestGenerateFingerprint/no_references (0.00s)2507 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2508=== RUN TestExternalSignerErrors/too_few_signatures2509=== PAUSE TestExternalSignerErrors/too_few_signatures2510=== RUN TestExternalSignerErrors/wrong_signature_length2511=== PAUSE TestExternalSignerErrors/wrong_signature_length2512=== RUN TestExternalSignerErrors/program_error2513=== PAUSE TestExternalSignerErrors/program_error2514=== CONT TestExternalSignerErrors/invalid_JSON2515=== CONT TestExternalSignerErrors/exit_on_request2516=== CONT TestExternalSignerErrors/program_error2517--- PASS: TestExternalSigner (0.01s)2518=== CONT TestExternalSignerErrors/wrong_signature_length2519=== CONT TestExternalSignerErrors/too_few_signatures2520=== CONT TestExternalSignerErrors/wrong_signature_name2521=== CONT TestExternalSignerErrors/null2522=== CONT TestExternalSignerErrors/wrong_id2523=== CONT TestExternalSignerErrors/wrong_signatures_shape2524=== CONT TestExternalSignerErrors/exit_at_startup2525=== CONT TestExternalSignerErrors/unrequested_key2526=== CONT TestExternalSignerErrors/missing_signatures2527=== CONT TestExternalSignerErrors/invalid_signature_base642528=== CONT TestExternalSignerErrors/null_signatures2529=== CONT TestExternalSignerErrors/wrong_shape2530=== CONT TestExternalSignerErrors/missing_signature_name2531--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2532--- PASS: TestExternalSignerErrors (0.01s)2533 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2534 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2535 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2536 --- PASS: TestExternalSignerErrors/null (0.00s)2537 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2538 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2539 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2540 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2541 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2542 --- PASS: TestExternalSignerErrors/program_error (0.01s)2543 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2544 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2545 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2546 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2547 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2548 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2549--- PASS: TestExternalSignerCancellation (0.02s)2550PASS2551Running OpenBao signer tests...2552=== RUN TestSign2553=== PAUSE TestSign2554=== RUN TestSignErrors2555=== PAUSE TestSignErrors2556=== RUN TestServe2557=== PAUSE TestServe2558=== RUN TestServeRejectsGarbage2559=== PAUSE TestServeRejectsGarbage2560=== CONT TestSign2561=== CONT TestServeRejectsGarbage2562=== CONT TestSignErrors2563=== CONT TestServe2564--- PASS: TestServeRejectsGarbage (0.00s)2565=== RUN TestSignErrors/http_error2566=== PAUSE TestSignErrors/http_error2567=== RUN TestSignErrors/invalid_json2568=== PAUSE TestSignErrors/invalid_json2569=== RUN TestSignErrors/no_prefix2570=== PAUSE TestSignErrors/no_prefix2571=== RUN TestSignErrors/invalid_base642572=== PAUSE TestSignErrors/invalid_base642573=== CONT TestSignErrors/http_error2574=== CONT TestSignErrors/no_prefix2575--- PASS: TestServe (0.00s)2576=== CONT TestSignErrors/invalid_base642577=== CONT TestSignErrors/invalid_json2578--- PASS: TestSignErrors (0.00s)2579 --- PASS: TestSignErrors/invalid_json (0.00s)2580 --- PASS: TestSignErrors/invalid_base64 (0.00s)2581 --- PASS: TestSignErrors/http_error (0.00s)2582 --- PASS: TestSignErrors/no_prefix (0.00s)2583--- PASS: TestSign (0.00s)2584PASS