niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #361
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestScriptTokenCachesUntilRefresh101=== CONT TestScriptTokenEmptyCommand102=== CONT TestScriptTokenScriptFails103=== CONT TestScriptTokenBadJSON104=== CONT TestDumpPathWriterError105=== CONT TestRateLimiterFeedback106=== RUN TestRateLimiterFeedback/429_enables_limiter107=== PAUSE TestRateLimiterFeedback/429_enables_limiter108=== CONT TestPathInfoCACompatibility109=== RUN TestPathInfoCACompatibility/null_ca_field110=== CONT TestParsePathInfoJSONMultiplePaths111=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths112=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths113=== CONT TestParsePathInfoJSON114=== CONT TestPathInfoHashCompatibility115=== CONT TestEncodeNixBase32WithRealHash116=== CONT TestEncodeNixBase32117=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess118=== CONT TestUploadMultipart_PartsInParallel119=== CONT TestScriptTokenNoExpiryRerunsEveryCall120=== CONT TestDumpPathSingleFile121=== CONT TestFileTokenEmpty122=== CONT TestDumpPathMatchesNix123=== CONT TestFileTokenMissing124=== CONT TestUploadMultipart_SupersededByPeer125=== CONT TestFileTokenReadsAndCaches126=== CONT TestPartSizeForNAR127=== CONT TestStaticToken128--- PASS: TestScriptTokenEmptyCommand (0.00s)129=== CONT TestSetClientTLSErrors130=== RUN TestRateLimiterFeedback/503_enables_limiter131=== PAUSE TestPathInfoCACompatibility/null_ca_field132=== RUN TestParsePathInfoJSON/Nix_format133=== CONT TestStreamPushIsolatesFailures134--- PASS: TestScriptTokenScriptFails (0.00s)135=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)136--- PASS: TestEncodeNixBase32WithRealHash (0.00s)137=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== CONT TestSetClientTLSDoesNotMutateDefaultTransport139=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon140=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon141=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI142=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI143=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths144=== RUN TestUploadMultipart_SupersededByPeer/exists145=== PAUSE TestRateLimiterFeedback/503_enables_limiter146=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter1472026/10/06 07:35:36 WARN Rate limiter enabled after throttle name=server-test rate=5148=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512149--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)150=== CONT TestStreamPushBatchesUnderLoad151=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter152=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter153=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths154=== RUN TestPartSizeForNAR/zero_stays_at_minimum155--- PASS: TestScriptTokenBadJSON (0.03s)156=== CONT TestSetClientTLS157=== RUN TestEncodeNixBase32/test_string_hash158=== RUN TestPathInfoCACompatibility/old_string_format_-_text159=== PAUSE TestParsePathInfoJSON/Nix_format160=== RUN TestParsePathInfoJSON/Lix_format161=== PAUSE TestEncodeNixBase32/test_string_hash162=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text163=== RUN TestEncodeNixBase32/empty_input1642026/10/06 07:35:36 ERROR Upload failed error="bad path" count=3165=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive166=== PAUSE TestUploadMultipart_SupersededByPeer/exists167=== RUN TestUploadMultipart_SupersededByPeer/missing168=== PAUSE TestUploadMultipart_SupersededByPeer/missing169=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512170=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive171=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter172=== RUN TestPathInfoCACompatibility/new_structured_format_-_text173=== CONT TestShellSplit174=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text175=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum176=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method177=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method178=== CONT TestGetStorePathHash179=== RUN TestGetStorePathHash/valid_store_path180=== PAUSE TestGetStorePathHash/valid_store_path181=== RUN TestPartSizeForNAR/small_stays_at_minimum182=== PAUSE TestEncodeNixBase32/empty_input183=== CONT TestScriptTokenEmptyToken184--- PASS: TestStaticToken (0.00s)185--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)186--- PASS: TestStreamPushIsolatesFailures (0.00s)187=== CONT TestShellSplitErrors188=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun189=== CONT TestFilterOversizedClosures190=== RUN TestFilterOversizedClosures/no_limit_keeps_everything191=== CONT TestCaseHackSuffix192=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything193=== CONT TestClientSignaturesByStorePath194=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica195=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped196=== CONT TestDoWithRetry_BodyReplayedViaGetBody197=== RUN TestSetClientTLSErrors/missing_cert_file198=== CONT TestRegisterUploadedObjectReusesConnections199=== CONT TestStreamPushGivesUpOnDeadServer200=== PAUSE TestParsePathInfoJSON/Lix_format201=== RUN TestParsePathInfoJSON/empty_input2022026/10/06 07:35:36 ERROR Upload failed error="connection refused" count=20203=== PAUSE TestParsePathInfoJSON/empty_input2042026/10/06 07:35:36 ERROR Server seems unavailable, giving up on batch untried=17205=== RUN TestParsePathInfoJSON/whitespace_only206=== PAUSE TestParsePathInfoJSON/whitespace_only207=== RUN TestParsePathInfoJSON/invalid_JSON208=== PAUSE TestParsePathInfoJSON/invalid_JSON209=== CONT TestResolveStorePath210=== CONT TestUploadMultipart_SupersededByPeer/exists2112026/10/06 07:35:36 INFO Garbage collection started212=== CONT TestConvertHashToNix32213=== RUN TestConvertHashToNix32/SRI_format_to_Nix32214=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32215=== RUN TestConvertHashToNix32/already_Nix32_format216=== PAUSE TestConvertHashToNix32/already_Nix32_format2172026/10/06 07:35:36 INFO Garbage collection started218=== RUN TestConvertHashToNix32/invalid_format219=== PAUSE TestConvertHashToNix32/invalid_format220=== RUN TestSetClientTLS/rejects_connection_without_client_cert221=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert222=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA223=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA2242026/10/06 07:35:36 WARN Rate limiter enabled after throttle name=server-test rate=5225=== RUN TestSetClientTLS/preserves_debug_logging_transport226=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2272026/10/06 07:35:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42531228=== CONT TestUploadMultipart_SupersededByPeer/missing229=== CONT TestRateLimiterFeedback/429_enables_limiter2302026/10/06 07:35:36 WARN Rate limiter backed off name=server-test rate=52312026/10/06 07:35:36 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42531232=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)233=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI234=== CONT TestStreamPushReportsEveryPath235=== PAUSE TestPartSizeForNAR/small_stays_at_minimum236--- PASS: TestDoServerRequestAttachesToken (0.03s)237=== CONT TestStreamPushReportsSignatures238=== CONT TestStreamPushRequestLine239=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== PAUSE TestSetClientTLSErrors/missing_cert_file241=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter242=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter243=== RUN TestGetStorePathHash/basename_without_hyphen_should_error244=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error245=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error246=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error247=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error248=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error249=== RUN TestSetClientTLSErrors/missing_key_file250=== PAUSE TestSetClientTLSErrors/missing_key_file251=== RUN TestSetClientTLSErrors/missing_ca_file252=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths253=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum254=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512255=== PAUSE TestSetClientTLSErrors/missing_ca_file256=== RUN TestSetClientTLSErrors/invalid_ca_file257=== PAUSE TestSetClientTLSErrors/invalid_ca_file258=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths259--- PASS: TestStreamPushReportsEveryPath (0.00s)260=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method261=== CONT TestPathInfoCACompatibility/old_string_format_-_text262--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)263 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)264 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)265--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)266--- PASS: TestShellSplitErrors (0.00s)267--- PASS: TestFileTokenMissing (0.00s)268=== CONT TestRateLimiterFeedback/503_enables_limiter269=== CONT TestParsePathInfoJSON/empty_input270=== CONT TestConvertHashToNix32/SRI_format_to_Nix322712026/10/06 07:35:36 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=0272=== CONT TestParsePathInfoJSON/invalid_JSON2732026/10/06 07:35:36 ERROR Upload failed error=boom count=1274=== CONT TestSetClientTLS/rejects_connection_without_client_cert2752026/10/06 07:35:36 ERROR Upload failed error=boom count=1276=== CONT TestPathInfoCACompatibility/null_ca_field277=== CONT TestParsePathInfoJSON/Lix_format278=== CONT TestSetClientTLS/preserves_debug_logging_transport279=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA280=== CONT TestParsePathInfoJSON/whitespace_only281=== CONT TestConvertHashToNix32/invalid_format2822026/10/06 07:35:36 WARN Rate limiter enabled after throttle name=server-test rate=5283=== CONT TestConvertHashToNix32/already_Nix32_format2842026/10/06 07:35:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:37525285=== CONT TestGetStorePathHash/valid_store_path286=== CONT TestEncodeNixBase32/test_string_hash2872026/10/06 07:35:36 WARN Rate limiter enabled after throttle name=server-test rate=5288=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error2892026/10/06 07:35:36 WARN Rate limiter backed off name=server-test rate=5290=== CONT TestGetStorePathHash/basename_without_hyphen_should_error2912026/10/06 07:35:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39299292=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum293=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon294=== RUN TestFilterOversizedClosures/all_closures_skipped295=== CONT TestEncodeNixBase32/empty_input296=== CONT TestParsePathInfoJSON/Nix_format2972026/10/06 07:35:36 WARN Rate limiter backed off name=server-test rate=5298=== CONT TestSetClientTLSErrors/missing_key_file299--- PASS: TestFileTokenReadsAndCaches (0.00s)300--- PASS: TestClientSignaturesByStorePath (0.00s)301=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive302=== CONT TestSetClientTLSErrors/missing_ca_file303=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error304=== CONT TestPathInfoCACompatibility/new_structured_format_-_text305=== CONT TestSetClientTLSErrors/missing_cert_file306=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts307=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts308=== RUN TestPartSizeForNAR/1_TiB309=== PAUSE TestPartSizeForNAR/1_TiB310=== RUN TestPartSizeForNAR/5_TiB_S3_max_object311=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object312=== RUN TestPartSizeForNAR/capped_at_5_GiB313=== PAUSE TestPartSizeForNAR/capped_at_5_GiB314=== CONT TestPartSizeForNAR/zero_stays_at_minimum315=== PAUSE TestFilterOversizedClosures/all_closures_skipped316=== CONT TestFilterOversizedClosures/no_limit_keeps_everything317=== CONT TestPartSizeForNAR/capped_at_5_GiB318=== CONT TestPartSizeForNAR/5_TiB_S3_max_object319=== CONT TestPartSizeForNAR/1_TiB320=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts321=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum322=== CONT TestPartSizeForNAR/small_stays_at_minimum323=== CONT TestSetClientTLSErrors/invalid_ca_file324--- PASS: TestFileTokenEmpty (0.00s)325--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)326--- PASS: TestResolveStorePath (0.00s)327=== CONT TestFilterOversizedClosures/all_closures_skipped3282026/10/06 07:35:36 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=50329=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3302026/10/06 07:35:36 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=2000331--- PASS: TestScriptTokenEmptyToken (0.00s)332--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)333--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)334--- PASS: TestShellSplit (0.00s)335--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)336 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)337 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)338--- PASS: TestStreamPushReportsSignatures (0.00s)339--- PASS: TestPathInfoCACompatibility (0.03s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)342 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)343 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)344 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)345--- PASS: TestConvertHashToNix32 (0.00s)346 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)347 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)348 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)349--- PASS: TestGetStorePathHash (0.00s)350 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)351 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)352 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)353 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)354--- PASS: TestEncodeNixBase32 (0.00s)355 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)356 --- PASS: TestEncodeNixBase32/empty_input (0.00s)357--- PASS: TestRateLimiterFeedback (0.03s)358 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)360 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)361 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3622026/10/06 07:35:36 WARN Garbage collection finished on another replica. Its statistics are not available here363--- PASS: TestPathInfoHashCompatibility (0.03s)364 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)365 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)366 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)367 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)368--- PASS: TestFilterOversizedClosures (0.00s)369 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)370 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)371 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)372--- PASS: TestPartSizeForNAR (0.01s)373 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)375 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)376 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)377 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)378 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)379 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)380--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)381--- PASS: TestSetClientTLSErrors (0.00s)382 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)383 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)384 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)385 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)386--- PASS: TestParsePathInfoJSON (0.03s)387 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)388 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)389 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)390 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)391 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)3922026/10/06 07:35:36 http: TLS handshake error from 127.0.0.1:46164: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.00s)394 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397--- PASS: TestCaseHackSuffix (0.03s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)399--- PASS: TestDumpPathSingleFile (0.03s)400--- PASS: TestStreamPushRequestLine (0.03s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestDumpPathMatchesNix (0.08s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1079984312/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/postgres1079984312/data -l logfile start434435/build/postgres1079984312:5432 - no response4362026-10-06 07:35:38.590 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 07:35:38.591 UTC [128] LOG: listening on Unix socket "/build/postgres1079984312/.s.PGSQL.5432"4382026-10-06 07:35:38.595 UTC [135] LOG: database system was shut down at 2026-10-06 07:35:38 UTC4392026-10-06 07:35:38.599 UTC [128] LOG: database system is ready to accept connections440/build/postgres1079984312:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/06 07:35:39 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 07:35:39 INFO lead: released remote=192.0.2.1:12344882026/10/06 07:35:39 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 07:35:40 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.84s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 07:35:40 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 07:35:42.288 UTC [384] FATAL: terminating connection due to administrator command4982026/10/06 07:35:42 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 07:35:43 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 07:35:43 INFO lead: released remote=192.0.2.1:12345012026/10/06 07:35:43 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (3.15s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyOutlastsServerWriteTimeout612=== PAUSE TestReadProxyOutlastsServerWriteTimeout613=== RUN TestReadProxyConditionalGet614=== PAUSE TestReadProxyConditionalGet615=== RUN TestReadProxyRootRedirectsToIndexHTML616=== PAUSE TestReadProxyRootRedirectsToIndexHTML617=== RUN TestReadProxyDisabled618=== PAUSE TestReadProxyDisabled619=== RUN TestReadRedirectNar620=== PAUSE TestReadRedirectNar621=== RUN TestReadRedirectKeepsNarinfoProxied622=== PAUSE TestReadRedirectKeepsNarinfoProxied623=== RUN TestReadProxyRangeRequest624=== PAUSE TestReadProxyRangeRequest625=== RUN TestReadRedirectUsesPublicS3URL626=== PAUSE TestReadRedirectUsesPublicS3URL627=== RUN TestPush_OverlappingRootsStoreOneRowPerKey628=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey629=== RUN TestPush_CompleteCommitsEveryRoot630=== PAUSE TestPush_CompleteCommitsEveryRoot631=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit632=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit633=== RUN TestPush_RejectsBadRequests634=== PAUSE TestPush_RejectsBadRequests635=== RUN TestPush_SignsNarinfosOfItsPendingObjects636=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects637=== RUN TestRedundantMultipartUpload638=== PAUSE TestRedundantMultipartUpload639=== RUN TestCompleteMultipartUpload_ErrorButObjectExists640=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists641=== RUN TestCompletedNarNotReofferedAcrossClosures642=== PAUSE TestCompletedNarNotReofferedAcrossClosures643=== RUN TestPresignedUploadRegisteredBeforeCommit644=== PAUSE TestPresignedUploadRegisteredBeforeCommit645=== RUN TestService_Rustfstest646=== PAUSE TestService_Rustfstest647=== RUN TestParseSize648=== PAUSE TestParseSize649=== RUN TestSkippedUploadsHandler650=== PAUSE TestSkippedUploadsHandler651=== RUN TestSystemdListenerNotActivated652--- PASS: TestSystemdListenerNotActivated (0.00s)653=== RUN TestWatchdogBeatsWhenHealthy654--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)655=== RUN TestWatchdogSkipsWhenUnhealthy6562026/10/06 07:35:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/06 07:35:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/06 07:35:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 07:35:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 07:35:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 07:35:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 07:35:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 07:35:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 07:35:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 07:35:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"666--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)667=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle668=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle669=== RUN TestProxyWriteTimeout670=== PAUSE TestProxyWriteTimeout671=== RUN TestPendingClosureWriteTimeout672=== PAUSE TestPendingClosureWriteTimeout673=== RUN TestIsValidUploadKey674=== PAUSE TestIsValidUploadKey675=== RUN TestUploadHandlersRejectInvalidKeys676=== PAUSE TestUploadHandlersRejectInvalidKeys677=== RUN TestUploadHandlersRejectOversizedBody678=== PAUSE TestUploadHandlersRejectOversizedBody679=== RUN TestService_cleanupPendingClosuresHandler680=== PAUSE TestService_cleanupPendingClosuresHandler681=== RUN TestService_createPendingClosureHandler682=== PAUSE TestService_createPendingClosureHandler683=== RUN TestService_verifyS3Integrity684=== PAUSE TestService_verifyS3Integrity685=== RUN TestCompleteMultipartUnregistered686=== PAUSE TestCompleteMultipartUnregistered687=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT688=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT689=== CONT TestPresignedUploadRegisteredBeforeCommit690=== CONT TestService_AuthMiddleware691=== CONT TestCompletedNarNotReofferedAcrossClosures692=== CONT TestCompleteMultipartUpload_ErrorButObjectExists693=== CONT TestGCTaskStore_GetEmpty694--- PASS: TestGCTaskStore_GetEmpty (0.00s)695=== CONT TestPinProtectsFromGC696=== CONT TestGCTaskStore_ConflictDifferentParams697--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)698=== CONT TestPush_OverlappingRootsStoreOneRowPerKey699=== CONT TestGCTaskStore_DeduplicateSameParams700--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)701=== CONT TestGCTaskStore_StartNew702--- PASS: TestGCTaskStore_StartNew (0.00s)703=== CONT TestReadRedirectUsesPublicS3URL704=== CONT TestClientSharedPathCommittedMidPush705=== CONT TestGCEndsOnShutdown706=== CONT TestPushWaitsForSweepHoldingRow707=== CONT TestSweepRechecksPendingAfterLocking708=== CONT TestGetExistingObjectsLocksRows709=== CONT TestGCTaskStore_GetReturnsLatest710=== CONT TestCommitRacingPendingCleanupKeepsObjects711=== CONT TestRedundantMultipartUpload712=== CONT TestRegisterCompletedObjectNeedsPendingRow713=== CONT TestPush_SignsNarinfosOfItsPendingObjects714=== CONT TestSweepSkipsRowsLockedByPush715=== CONT TestPush_RejectsBadRequests716=== CONT TestFailedS3DeleteKeepsTombstone717=== CONT TestForceGCDuringPushOffersSweptObject718=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit719=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection720=== CONT TestPush_CompleteCommitsEveryRoot721=== RUN TestGCEndsOnShutdown/before_the_run722=== PAUSE TestGCEndsOnShutdown/before_the_run723=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete724=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete725=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark726=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark727=== CONT TestClientWithDependencies728=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows729=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows730=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check731=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check732=== CONT TestReadProxyRangeRequest733--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)734=== CONT TestClientMultipleUploads7352026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures7362026/10/06 07:35:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"737--- PASS: TestService_AuthMiddleware (0.29s)738=== CONT TestReadRedirectKeepsNarinfoProxied7392026/10/06 07:35:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7402026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures7412026/10/06 07:35:44 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LmRiODUxMDVhLTVjMWUtNDkwNi1iMGYwLWJlZWM0NGVhZTRlMHgxNzkxMjcyMTQ0Mzk2NzE5NDg27422026/10/06 07:35:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LmRiODUxMDVhLTVjMWUtNDkwNi1iMGYwLWJlZWM0NGVhZTRlMHgxNzkxMjcyMTQ0Mzk2NzE5NDg2 parts=1743--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.32s)744=== CONT TestClientIntegration7452026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures7462026/10/06 07:35:44 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7472026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures748--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.34s)749=== CONT TestReadRedirectNar750--- PASS: TestReadRedirectUsesPublicS3URL (0.39s)751=== CONT TestClientErrorHandling752=== RUN TestClientErrorHandling/InvalidStorePath753=== PAUSE TestClientErrorHandling/InvalidStorePath754=== RUN TestClientErrorHandling/InvalidAuthToken755=== PAUSE TestClientErrorHandling/InvalidAuthToken756=== RUN TestClientErrorHandling/ServerNotAvailable757=== PAUSE TestClientErrorHandling/ServerNotAvailable758=== CONT TestReadProxyDisabled7592026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes7602026/10/06 07:35:44 INFO Received complete push request method=POST path=/api/pushes/1/complete761=== NAME TestPinProtectsFromGC762 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3272337281/001/store/ia9093jnl02zmpq6v5g2qpl0aylwhj16-pinned-file.txt763 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3272337281/001/store/0pbkb6w5fv0gr50g74lyj85gvh0iswaa-unpinned-file.txt7642026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures765--- PASS: TestPush_CompleteCommitsEveryRoot (0.42s)766=== CONT TestClientCADerivations7672026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures768=== NAME TestClientWithDependencies769 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies517290662/001/store/gvp5vzb6i5kxym7ynf1mpfs57p3y0mqc-test-script770--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.46s)771=== CONT TestReadProxyRootRedirectsToIndexHTML7722026/10/06 07:35:44 INFO Aborted multipart uploads count=0 kept=07732026/10/06 07:35:44 WARN Force mode enabled - objects will be deleted immediately without grace period774=== NAME TestClientWithDependencies775 client_integration_test.go:615: Found 1 dependencies (including self)7762026/10/06 07:35:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=0777=== RUN TestPush_RejectsBadRequests/no_roots778=== PAUSE TestPush_RejectsBadRequests/no_roots779=== RUN TestPush_RejectsBadRequests/no_objects780=== PAUSE TestPush_RejectsBadRequests/no_objects781=== RUN TestPush_RejectsBadRequests/bad_root782=== PAUSE TestPush_RejectsBadRequests/bad_root783=== RUN TestPush_RejectsBadRequests/root_not_in_objects784=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects785=== CONT TestCacheStatsHandler7862026/10/06 07:35:44 INFO Vacuumed table table=pending_closures7872026/10/06 07:35:44 INFO Vacuumed table table=pending_objects7882026/10/06 07:35:44 INFO Vacuumed table table=multipart_uploads7892026/10/06 07:35:44 INFO Vacuumed table table=closures7902026/10/06 07:35:44 INFO Vacuumed table table=objects791--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.49s)792=== CONT TestReadProxyConditionalGet7932026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes7942026/10/06 07:35:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)7952026/10/06 07:35:44 INFO Uploading ia9093jnl02zmpq6v5g2qpl0aylwhj16-pinned-file.txt (128B)7962026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"7972026/10/06 07:35:44 WARN Failed to register uploaded object key=ia9093jnl02zmpq6v5g2qpl0aylwhj16.ls error="server returned 404: 404 page not found\n"7982026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7992026/10/06 07:35:44 INFO Signed narinfos id=1 count=18002026/10/06 07:35:44 INFO Uploading 1 narinfos8012026/10/06 07:35:44 INFO Received complete push request method=POST path=/api/pushes/1/complete8022026/10/06 07:35:44 WARN Failed to register uploaded object key=ia9093jnl02zmpq6v5g2qpl0aylwhj16.narinfo error="server returned 404: 404 page not found\n"8032026/10/06 07:35:44 INFO Aborted multipart uploads count=0 kept=08042026/10/06 07:35:44 WARN Force mode enabled - objects will be deleted immediately without grace period8052026/10/06 07:35:44 INFO Upload complete. (69ms)806--- PASS: TestGetExistingObjectsLocksRows (0.53s)807=== CONT TestReadProxyOutlastsServerWriteTimeout8082026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes8092026/10/06 07:35:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08102026/10/06 07:35:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8112026/10/06 07:35:44 INFO Uploading gvp5vzb6i5kxym7ynf1mpfs57p3y0mqc-test-script (136B)8122026/10/06 07:35:44 INFO Vacuumed table table=pending_closures8132026/10/06 07:35:44 INFO Vacuumed table table=pending_objects8142026/10/06 07:35:44 INFO Vacuumed table table=multipart_uploads8152026/10/06 07:35:44 WARN Failed to register uploaded object key=gvp5vzb6i5kxym7ynf1mpfs57p3y0mqc.ls error="server returned 404: 404 page not found\n"8162026/10/06 07:35:44 INFO Vacuumed table table=closures8172026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"8182026/10/06 07:35:44 WARN Failed to register uploaded object key=log/1jgd71dk70zvpvxkramx185ni29zlf09-test-script.drv error="server returned 404: 404 page not found\n"8192026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8202026/10/06 07:35:44 INFO Signed narinfos id=1 count=18212026/10/06 07:35:44 INFO Uploading 1 narinfos8222026/10/06 07:35:44 INFO Vacuumed table table=objects823--- PASS: TestSweepRechecksPendingAfterLocking (0.58s)824=== CONT TestService_ReadScope_PublicByDefault8252026/10/06 07:35:44 INFO Received complete push request method=POST path=/api/pushes/1/complete8262026/10/06 07:35:44 WARN Failed to register uploaded object key=gvp5vzb6i5kxym7ynf1mpfs57p3y0mqc.narinfo error="server returned 404: 404 page not found\n"8272026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures8282026/10/06 07:35:44 INFO Upload complete. (80ms)829=== NAME TestClientWithDependencies830 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies517290662/001/store) requires matching store prefix8312026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes832--- PASS: TestClientWithDependencies (0.60s)833=== CONT TestClientPushesUseOnePush8342026/10/06 07:35:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8352026/10/06 07:35:44 INFO Uploading 0pbkb6w5fv0gr50g74lyj85gvh0iswaa-unpinned-file.txt (128B)8362026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"8372026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes8382026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign8392026/10/06 07:35:44 INFO Signed narinfos id=2 count=18402026/10/06 07:35:44 WARN Failed to register uploaded object key=0pbkb6w5fv0gr50g74lyj85gvh0iswaa.ls error="server returned 404: 404 page not found\n"8412026/10/06 07:35:44 INFO Uploading 1 narinfos8422026/10/06 07:35:44 INFO Received complete push request method=POST path=/api/pushes/2/complete8432026/10/06 07:35:44 WARN Failed to register uploaded object key=0pbkb6w5fv0gr50g74lyj85gvh0iswaa.narinfo error="server returned 404: 404 page not found\n"8442026/10/06 07:35:44 INFO Upload complete. (52ms)8452026/10/06 07:35:44 INFO Received complete push request method=POST path=/api/pushes/1/complete8462026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes8472026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes848--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.65s)849=== CONT TestReadProxyHead8502026/10/06 07:35:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures8512026/10/06 07:35:44 INFO Garbage collection started8522026/10/06 07:35:44 INFO Aborted multipart uploads count=0 kept=08532026/10/06 07:35:44 WARN Force mode enabled - objects will be deleted immediately without grace period8542026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures8552026/10/06 07:35:44 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=08562026/10/06 07:35:44 INFO Vacuumed table table=pending_closures8572026/10/06 07:35:44 INFO Vacuumed table table=pending_objects8582026/10/06 07:35:44 INFO Aborted multipart uploads count=0 kept=08592026/10/06 07:35:44 INFO Vacuumed table table=multipart_uploads8602026/10/06 07:35:44 INFO Vacuumed table table=closures8612026/10/06 07:35:44 WARN Force mode enabled - objects will be deleted immediately without grace period8622026/10/06 07:35:44 INFO Vacuumed table table=objects8632026/10/06 07:35:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8642026/10/06 07:35:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=08652026/10/06 07:35:44 INFO Vacuumed table table=pending_closures8662026/10/06 07:35:44 INFO Vacuumed table table=pending_objects8672026/10/06 07:35:44 INFO Vacuumed table table=multipart_uploads8682026/10/06 07:35:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LmRjYTVmZDc5LWNmYTAtNDZjMy1iMDdmLTI4YjBjZTZkZTgwMHgxNzkxMjcyMTQ0NDMxNDY3MTQ1 parts=128692026/10/06 07:35:44 INFO Vacuumed table table=closures8702026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures8712026/10/06 07:35:44 INFO Vacuumed table table=objects8722026/10/06 07:35:44 INFO Received complete push request method=POST path=/api/pushes/2/complete873--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.72s)874=== CONT TestCacheConfigHandler875=== RUN TestCacheConfigHandler/full_config,_no_issuer876=== PAUSE TestCacheConfigHandler/full_config,_no_issuer877=== RUN TestCacheConfigHandler/no_cache_url_configured878=== PAUSE TestCacheConfigHandler/no_cache_url_configured879=== RUN TestCacheConfigHandler/no_signing_keys880=== PAUSE TestCacheConfigHandler/no_signing_keys881=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator882=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator883=== CONT TestReadProxyInvalidPath884--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.72s)885=== CONT TestReadProxy404886--- PASS: TestReadProxyRangeRequest (0.72s)887=== CONT TestReadProxyNarStreaming888=== NAME TestClientMultipleUploads889 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3821246532/001/store/cc5pq4s09zdapm2bk1ijhvlzb711r2lj-test-file-0.txt8902026/10/06 07:35:44 INFO Aborted multipart uploads count=0 kept=08912026/10/06 07:35:44 WARN Force mode enabled - objects will be deleted immediately without grace period8922026/10/06 07:35:44 INFO Aborted multipart uploads count=0 kept=08932026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures8942026/10/06 07:35:44 WARN Force mode enabled - objects will be deleted immediately without grace period8952026/10/06 07:35:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08962026/10/06 07:35:44 INFO Vacuumed table table=pending_closures8972026/10/06 07:35:44 INFO Vacuumed table table=pending_objects8982026/10/06 07:35:44 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8992026/10/06 07:35:44 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."9002026/10/06 07:35:44 INFO Vacuumed table table=multipart_uploads9012026/10/06 07:35:44 INFO Vacuumed table table=closures902 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3821246532/001/store/svb958v9ccwxj9p7ldxrfilvrpzkx3ar-test-file-1.txt903--- PASS: TestFailedS3DeleteKeepsTombstone (0.77s)904=== CONT TestReadProxyNarinfoAlreadyDecompressed9052026/10/06 07:35:44 INFO Vacuumed table table=objects9062026/10/06 07:35:44 INFO Aborted multipart uploads count=0 kept=09072026/10/06 07:35:44 WARN Force mode enabled - objects will be deleted immediately without grace period9082026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes9092026/10/06 07:35:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=09102026/10/06 07:35:44 INFO Vacuumed table table=pending_closures9112026/10/06 07:35:44 INFO Vacuumed table table=pending_objects9122026/10/06 07:35:44 INFO Vacuumed table table=multipart_uploads9132026/10/06 07:35:44 INFO Vacuumed table table=closures9142026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9152026/10/06 07:35:44 INFO Signed narinfos id=1 count=19162026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9172026/10/06 07:35:44 INFO Vacuumed table table=objects9182026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9192026/10/06 07:35:44 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9202026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9212026/10/06 07:35:44 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9222026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9232026/10/06 07:35:44 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19242026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9252026/10/06 07:35:44 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo926--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.79s)927=== CONT TestReadProxyNarinfo928--- PASS: TestSweepSkipsRowsLockedByPush (0.79s)929=== CONT TestIsValidCachePath930=== RUN TestIsValidCachePath/narinfo931=== PAUSE TestIsValidCachePath/narinfo932=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars933=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars934=== RUN TestIsValidCachePath/nar_zst935=== PAUSE TestIsValidCachePath/nar_zst936=== RUN TestIsValidCachePath/nar_xz937=== PAUSE TestIsValidCachePath/nar_xz938=== RUN TestIsValidCachePath/nar_bz2939=== PAUSE TestIsValidCachePath/nar_bz2940=== RUN TestIsValidCachePath/nar_uncompressed941=== PAUSE TestIsValidCachePath/nar_uncompressed942=== RUN TestIsValidCachePath/ls943=== PAUSE TestIsValidCachePath/ls944=== RUN TestIsValidCachePath/log945=== PAUSE TestIsValidCachePath/log946=== RUN TestIsValidCachePath/realisation947=== PAUSE TestIsValidCachePath/realisation948=== RUN TestIsValidCachePath/nix-cache-info949=== PAUSE TestIsValidCachePath/nix-cache-info950=== RUN TestIsValidCachePath/index.html951=== PAUSE TestIsValidCachePath/index.html952=== RUN TestIsValidCachePath/traversal_parent953=== PAUSE TestIsValidCachePath/traversal_parent954=== RUN TestIsValidCachePath/traversal_in_middle955=== PAUSE TestIsValidCachePath/traversal_in_middle956=== RUN TestIsValidCachePath/invalid_char_e957=== PAUSE TestIsValidCachePath/invalid_char_e958=== RUN TestIsValidCachePath/invalid_char_u959=== PAUSE TestIsValidCachePath/invalid_char_u960=== RUN TestIsValidCachePath/random_path961=== PAUSE TestIsValidCachePath/random_path962=== RUN TestIsValidCachePath/empty963=== PAUSE TestIsValidCachePath/empty964=== RUN TestIsValidCachePath/leading_slash965=== PAUSE TestIsValidCachePath/leading_slash966=== RUN TestIsValidCachePath/wrong_extension967=== PAUSE TestIsValidCachePath/wrong_extension968=== RUN TestIsValidCachePath/short_hash969=== PAUSE TestIsValidCachePath/short_hash970=== CONT TestProxyHeadersOnlyTrustedOnSocket971=== NAME TestClientMultipleUploads972 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3821246532/001/store/d8ksi4nrrlq30zsdv9rz5d9dlv84v16a-test-file-2.txt9732026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes974--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.80s)975=== CONT TestParseSingleRange976=== RUN TestParseSingleRange/none977=== PAUSE TestParseSingleRange/none978=== RUN TestParseSingleRange/unknown_unit979=== PAUSE TestParseSingleRange/unknown_unit980=== RUN TestParseSingleRange/multi-range_ignored981=== PAUSE TestParseSingleRange/multi-range_ignored982=== RUN TestParseSingleRange/malformed_no_dash983=== PAUSE TestParseSingleRange/malformed_no_dash984=== RUN TestParseSingleRange/malformed_both_empty985=== PAUSE TestParseSingleRange/malformed_both_empty986=== RUN TestParseSingleRange/malformed_end_before_start987=== PAUSE TestParseSingleRange/malformed_end_before_start988=== RUN TestParseSingleRange/closed989=== PAUSE TestParseSingleRange/closed990=== RUN TestParseSingleRange/open-ended991=== PAUSE TestParseSingleRange/open-ended992=== RUN TestParseSingleRange/end_clamped_to_size993=== PAUSE TestParseSingleRange/end_clamped_to_size994=== RUN TestParseSingleRange/suffix995=== PAUSE TestParseSingleRange/suffix996=== RUN TestParseSingleRange/suffix_exceeds_size997=== PAUSE TestParseSingleRange/suffix_exceeds_size998=== RUN TestParseSingleRange/single_byte999=== PAUSE TestParseSingleRange/single_byte1000=== RUN TestParseSingleRange/start_past_EOF1001=== PAUSE TestParseSingleRange/start_past_EOF1002=== RUN TestParseSingleRange/start_far_past_EOF1003=== PAUSE TestParseSingleRange/start_far_past_EOF1004=== CONT TestPresentNotReportedWhileGCDeletesClosure10052026/10/06 07:35:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10062026/10/06 07:35:44 INFO Uploading vs6yjgp0b1xzakvf1zh1f7588rbl08mk-shared-dep (136B)10072026/10/06 07:35:44 INFO Uploading nm84ri3zbxmzm4w9f4mgi9vix5y0lxxc-top (224B)1008--- PASS: TestReadRedirectKeepsNarinfoProxied (0.51s)1009=== CONT TestPresentReportsOnlyClosureRoots10102026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10112026/10/06 07:35:44 WARN Failed to register uploaded object key=vs6yjgp0b1xzakvf1zh1f7588rbl08mk.ls error="server returned 404: 404 page not found\n"10122026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10132026/10/06 07:35:44 WARN Failed to register uploaded object key=nm84ri3zbxmzm4w9f4mgi9vix5y0lxxc.ls error="server returned 404: 404 page not found\n"10142026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/1gfv6kk2c0hdb6nqkbqslxmjgwks2my0mfgsxfzb7bvpsqyx4ywp.nar.zst error="server returned 404: 404 page not found\n"10152026/10/06 07:35:44 INFO Signed narinfos id=1 count=210162026/10/06 07:35:44 INFO Uploading 2 narinfos10172026/10/06 07:35:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10182026/10/06 07:35:44 WARN Failed to register uploaded object key=nm84ri3zbxmzm4w9f4mgi9vix5y0lxxc.narinfo error="server returned 404: 404 page not found\n"10192026/10/06 07:35:44 WARN Failed to register uploaded object key=vs6yjgp0b1xzakvf1zh1f7588rbl08mk.narinfo error="server returned 404: 404 page not found\n"10202026/10/06 07:35:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10212026/10/06 07:35:44 INFO Upload complete. (58ms)1022=== NAME TestClientSharedPathCommittedMidPush1023 client_integration_test.go:680: Retrieved narinfo from S3:1024 StorePath: /build/TestClientSharedPathCommittedMidPush1257127769/001/store/vs6yjgp0b1xzakvf1zh1f7588rbl08mk-shared-dep1025 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1026 Compression: zstd1027 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821028 NarSize: 1361029 References: 1030 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1031 client_integration_test.go:680: Retrieved narinfo from S3:1032 StorePath: /build/TestClientSharedPathCommittedMidPush1257127769/001/store/nm84ri3zbxmzm4w9f4mgi9vix5y0lxxc-top1033 URL: nar/1gfv6kk2c0hdb6nqkbqslxmjgwks2my0mfgsxfzb7bvpsqyx4ywp.nar.zst1034 Compression: zstd1035 NarHash: sha256:1gfv6kk2c0hdb6nqkbqslxmjgwks2my0mfgsxfzb7bvpsqyx4ywp1036 NarSize: 2241037 References: /build/TestClientSharedPathCommittedMidPush1257127769/001/store/vs6yjgp0b1xzakvf1zh1f7588rbl08mk-shared-dep1038 CA: text:sha256:0pbga8mhn4y99ab83ifzwh7164bgldp6jif9i6j2bzl0agyb0wag1039--- PASS: TestClientSharedPathCommittedMidPush (0.83s)1040=== CONT TestCreatePin_ReservedPins10412026/10/06 07:35:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LjA5NjEzMTBkLWUzOGItNGE5Mi05OTk0LWExNmRiOTY0ZjcwMngxNzkxMjcyMTQ0NTM2MTczNDA2 parts=1210422026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures10432026/10/06 07:35:44 INFO Received uploads request method=POST path=/api/pending_closures1044--- PASS: TestReadRedirectNar (0.51s)1045=== CONT TestOrphanedObjectsGCStressTest1046=== NAME TestClientIntegration1047 client_integration_test.go:286: Created store path: /build/TestClientIntegration1695924497/002/store/18dqgm871y7421d7gqv946mc54324k32-test-file.txt1048--- PASS: TestReadProxyDisabled (0.48s)1049=== CONT TestGCSweepDeliversEachKeyOnce10502026/10/06 07:35:44 INFO Received push request method=POST path=/api/pushes10512026/10/06 07:35:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10522026/10/06 07:35:44 INFO Uploading d8ksi4nrrlq30zsdv9rz5d9dlv84v16a-test-file-2.txt (160B)10532026/10/06 07:35:44 INFO Uploading svb958v9ccwxj9p7ldxrfilvrpzkx3ar-test-file-1.txt (160B)10542026/10/06 07:35:44 INFO Uploading cc5pq4s09zdapm2bk1ijhvlzb711r2lj-test-file-0.txt (160B)10552026/10/06 07:35:44 WARN Failed to register uploaded object key=svb958v9ccwxj9p7ldxrfilvrpzkx3ar.ls error="server returned 404: 404 page not found\n"10562026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10572026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10582026/10/06 07:35:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10592026/10/06 07:35:44 WARN Failed to register uploaded object key=cc5pq4s09zdapm2bk1ijhvlzb711r2lj.ls error="server returned 404: 404 page not found\n"10602026/10/06 07:35:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10612026/10/06 07:35:44 WARN Failed to register uploaded object key=d8ksi4nrrlq30zsdv9rz5d9dlv84v16a.ls error="server returned 404: 404 page not found\n"10622026/10/06 07:35:44 INFO Signed narinfos id=1 count=310632026/10/06 07:35:44 INFO Uploading 3 narinfos10642026/10/06 07:35:45 WARN Failed to register uploaded object key=cc5pq4s09zdapm2bk1ijhvlzb711r2lj.narinfo error="server returned 404: 404 page not found\n"10652026/10/06 07:35:45 INFO Received complete push request method=POST path=/api/pushes/1/complete10662026/10/06 07:35:45 WARN Failed to register uploaded object key=d8ksi4nrrlq30zsdv9rz5d9dlv84v16a.narinfo error="server returned 404: 404 page not found\n"10672026/10/06 07:35:45 WARN Failed to register uploaded object key=svb958v9ccwxj9p7ldxrfilvrpzkx3ar.narinfo error="server returned 404: 404 page not found\n"10682026/10/06 07:35:45 INFO Upload complete. (66ms)1069=== NAME TestClientMultipleUploads1070 client_integration_test.go:369: Uploaded 3 paths in 99.662938ms1071--- PASS: TestClientMultipleUploads (0.90s)1072=== CONT TestOrphanedObjectsGC1073--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)1074=== CONT TestTombstonedObjectOfferedWithoutWaiting10752026/10/06 07:35:45 INFO Received push request method=POST path=/api/pushes10762026/10/06 07:35:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10772026/10/06 07:35:45 INFO Uploading 18dqgm871y7421d7gqv946mc54324k32-test-file.txt (152B)10782026/10/06 07:35:45 WARN Failed to register uploaded object key=18dqgm871y7421d7gqv946mc54324k32.ls error="server returned 404: 404 page not found\n"10792026/10/06 07:35:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10802026/10/06 07:35:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10812026/10/06 07:35:45 INFO Signed narinfos id=1 count=110822026/10/06 07:35:45 INFO Uploading 1 narinfos1083--- PASS: TestReadProxyConditionalGet (0.45s)1084=== CONT TestObjectStatsTrigger10852026/10/06 07:35:45 INFO Received complete push request method=POST path=/api/pushes/1/complete10862026/10/06 07:35:45 WARN Failed to register uploaded object key=18dqgm871y7421d7gqv946mc54324k32.narinfo error="server returned 404: 404 page not found\n"10872026/10/06 07:35:45 INFO Upload complete. (60ms)1088--- PASS: TestCacheStatsHandler (0.50s)1089=== CONT TestGCSweepSkipsPendingObjects1090=== NAME TestClientCADerivations1091 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3802761897/001/store/9037rkav21bvxcdbpswvf5nif4nhdgg7-ca-test10922026/10/06 07:35:45 INFO All 1 paths already cached1093=== NAME TestClientIntegration1094 client_integration_test.go:312: Retrieved narinfo from S3:1095 StorePath: /build/TestClientIntegration1695924497/002/store/18dqgm871y7421d7gqv946mc54324k32-test-file.txt1096 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1097 Compression: zstd1098 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11099 NarSize: 1521100 References: 1101 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11102 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1103 client_integration_test.go:313: Decompressed .ls content (64 bytes):1104 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1105 client_integration_test.go:316: Testing garbage collection...1106--- PASS: TestService_ReadScope_PublicByDefault (0.43s)1107=== CONT TestPendingCleanupUsesOneCutoff1108=== NAME TestClientCADerivations1109 client_ca_test.go:139: Found 1 dependencies (including self)11102026/10/06 07:35:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures11112026/10/06 07:35:45 INFO Garbage collection started11122026/10/06 07:35:45 INFO Aborted multipart uploads count=0 kept=011132026/10/06 07:35:45 WARN Force mode enabled - objects will be deleted immediately without grace period1114--- PASS: TestReadProxyHead (0.41s)1115=== CONT TestDeduplicatedObjectsRecordedAsPending11162026/10/06 07:35:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=011172026/10/06 07:35:45 INFO Vacuumed table table=pending_closures11182026/10/06 07:35:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37665/oidc11192026/10/06 07:35:45 INFO Vacuumed table table=pending_objects11202026/10/06 07:35:45 INFO Vacuumed table table=multipart_uploads11212026/10/06 07:35:45 INFO Vacuumed table table=closures11222026/10/06 07:35:45 INFO Vacuumed table table=objects1123--- PASS: TestReadProxyInvalidPath (0.35s)1124=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1125--- PASS: TestReadProxyNarStreaming (0.38s)1126=== CONT TestPushDedupSurvivesConcurrentGC11272026/10/06 07:35:45 INFO Received push request method=POST path=/api/pushes11282026/10/06 07:35:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11292026/10/06 07:35:45 INFO Uploading 9037rkav21bvxcdbpswvf5nif4nhdgg7-ca-test (144B)1130--- PASS: TestReadProxy404 (0.42s)1131=== CONT TestMultipartCleanup11322026/10/06 07:35:45 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11332026/10/06 07:35:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11342026/10/06 07:35:45 WARN Failed to register uploaded object key=9037rkav21bvxcdbpswvf5nif4nhdgg7.ls error="server returned 404: 404 page not found\n"11352026/10/06 07:35:45 WARN Failed to register uploaded object key=log/09qz7msrv960vyk102gqks90ypfv6xv3-ca-test.drv error="server returned 404: 404 page not found\n"11362026/10/06 07:35:45 INFO Signed narinfos id=1 count=111372026/10/06 07:35:45 INFO Uploading 1 narinfos11382026/10/06 07:35:45 INFO Received complete push request method=POST path=/api/pushes/1/complete11392026/10/06 07:35:45 WARN Failed to register uploaded object key=9037rkav21bvxcdbpswvf5nif4nhdgg7.narinfo error="server returned 404: 404 page not found\n"1140--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.38s)1141=== CONT TestGCMetrics11422026/10/06 07:35:45 INFO Upload complete. (108ms)1143=== NAME TestClientCADerivations1144 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3802761897/001/store/9037rkav21bvxcdbpswvf5nif4nhdgg7-ca-test1145 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1146 Compression: zstd1147 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1148 NarSize: 1441149 References: 1150 Deriver: /build/TestClientCADerivations3802761897/001/store/09qz7msrv960vyk102gqks90ypfv6xv3-ca-test.drv1151 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1152 client_ca_test.go:185: Checking for realisation files in S3...1153 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1154 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache11552026/10/06 07:35:45 INFO Received push request method=POST path=/api/pushes11562026/10/06 07:35:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11572026/10/06 07:35:45 INFO Uploading prdjij7gvn9imnn0jagc8l65k9saqxld-b (208B)11582026/10/06 07:35:45 INFO Uploading pyfnwmspnm33kwidns49xzn0zpdh2bmh-shared-dep (136B)11592026/10/06 07:35:45 WARN Failed to register uploaded object key=c32y72pwgvyql5axg3dafr52i5lgrz4v.ls error="server returned 404: 404 page not found\n"11602026/10/06 07:35:45 WARN Failed to register uploaded object key=nar/0jcxj3626srfmpfjziv9fr2yq4r0f6sfdwp7j49baybny06vlnmz.nar.zst error="server returned 404: 404 page not found\n"11612026/10/06 07:35:45 WARN Failed to register uploaded object key=pyfnwmspnm33kwidns49xzn0zpdh2bmh.ls error="server returned 404: 404 page not found\n"11622026/10/06 07:35:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11632026/10/06 07:35:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11642026/10/06 07:35:45 WARN Failed to register uploaded object key=prdjij7gvn9imnn0jagc8l65k9saqxld.ls error="server returned 404: 404 page not found\n"11652026/10/06 07:35:45 INFO Signed narinfos id=1 count=311662026/10/06 07:35:45 INFO Uploading 3 narinfos11672026/10/06 07:35:45 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket4266447531/001/proxy.sock11682026/10/06 07:35:45 INFO Starting HTTP server address=127.0.0.1:4372111692026/10/06 07:35:45 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11702026/10/06 07:35:45 INFO Shutdown signal received, draining in-flight requests timeout=10s1171--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.45s)1172=== CONT TestServerTLSConfig1173=== RUN TestServerTLSConfig/no_client_CA1174=== PAUSE TestServerTLSConfig/no_client_CA1175=== RUN TestServerTLSConfig/missing_CA_file1176=== PAUSE TestServerTLSConfig/missing_CA_file1177=== RUN TestServerTLSConfig/not_a_PEM_file1178=== PAUSE TestServerTLSConfig/not_a_PEM_file1179=== CONT TestGCBugBareHashReferences11802026/10/06 07:35:45 WARN Failed to register uploaded object key=prdjij7gvn9imnn0jagc8l65k9saqxld.narinfo error="server returned 404: 404 page not found\n"11812026/10/06 07:35:45 INFO Received complete push request method=POST path=/api/pushes/1/complete11822026/10/06 07:35:45 WARN Failed to register uploaded object key=c32y72pwgvyql5axg3dafr52i5lgrz4v.narinfo error="server returned 404: 404 page not found\n"11832026/10/06 07:35:45 WARN Failed to register uploaded object key=pyfnwmspnm33kwidns49xzn0zpdh2bmh.narinfo error="server returned 404: 404 page not found\n"11842026/10/06 07:35:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11852026/10/06 07:35:45 INFO Upload complete. (55ms)1186=== NAME TestClientPushesUseOnePush1187 client_pushes_test.go:97: Retrieved narinfo from S3:1188 StorePath: /build/TestClientPushesUseOnePush728999436/001/store/pyfnwmspnm33kwidns49xzn0zpdh2bmh-shared-dep1189 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1190 Compression: zstd1191 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821192 NarSize: 1361193 References: 1194 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1195 client_pushes_test.go:97: Retrieved narinfo from S3:1196 StorePath: /build/TestClientPushesUseOnePush728999436/001/store/c32y72pwgvyql5axg3dafr52i5lgrz4v-a1197 URL: nar/0jcxj3626srfmpfjziv9fr2yq4r0f6sfdwp7j49baybny06vlnmz.nar.zst1198 Compression: zstd1199 NarHash: sha256:0jcxj3626srfmpfjziv9fr2yq4r0f6sfdwp7j49baybny06vlnmz1200 NarSize: 2081201 References: /build/TestClientPushesUseOnePush728999436/001/store/pyfnwmspnm33kwidns49xzn0zpdh2bmh-shared-dep1202 CA: text:sha256:1pifagbapyz7b7ap96kgk7gbq8lm0zajq18yzd7nfs55hrvhk70s1203 client_pushes_test.go:97: Retrieved narinfo from S3:1204 StorePath: /build/TestClientPushesUseOnePush728999436/001/store/prdjij7gvn9imnn0jagc8l65k9saqxld-b1205 URL: nar/0jcxj3626srfmpfjziv9fr2yq4r0f6sfdwp7j49baybny06vlnmz.nar.zst1206 Compression: zstd1207 NarHash: sha256:0jcxj3626srfmpfjziv9fr2yq4r0f6sfdwp7j49baybny06vlnmz1208 NarSize: 2081209 References: /build/TestClientPushesUseOnePush728999436/001/store/pyfnwmspnm33kwidns49xzn0zpdh2bmh-shared-dep1210 CA: text:sha256:1pifagbapyz7b7ap96kgk7gbq8lm0zajq18yzd7nfs55hrvhk70s12112026/10/06 07:35:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LjU4NWU3OTllLWJlZGUtNGE5OC04ZGNkLWNlYmIwMWJkZmJkYngxNzkxMjcyMTQ0OTY0MjU0MDI5 error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12122026/10/06 07:35:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LmQ4MTlhNGY4LTg0YzMtNDgzNi1iMjVhLTJlN2Q2MTgwOTdiNngxNzkxMjcyMTQ0OTU3MTUzOTQ4 parts=1212132026/10/06 07:35:45 INFO Received cleanup request method=DELETE path=/api/pending_closures1214=== NAME TestClientCADerivations1215 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1216 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1217 error: binary cache 's3://bucket31?endpoint=http://localhost:39693®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3802761897/001/store'1218 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11219--- PASS: TestClientPushesUseOnePush (0.66s)1220=== CONT TestService_NativeMTLS12212026/10/06 07:35:45 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1222--- PASS: TestPushWaitsForSweepHoldingRow (1.26s)1223=== CONT TestGCAdvisoryLockBlocksConcurrentRun12242026/10/06 07:35:45 INFO Aborted multipart uploads count=1 kept=01225--- PASS: TestClientCADerivations (0.85s)1226=== CONT TestService_RequireScope_OIDC1227--- PASS: TestRedundantMultipartUpload (1.26s)1228=== CONT TestMetricsInventory1229--- PASS: TestPresentReportsOnlyClosureRoots (0.49s)1230=== CONT TestLeadEndsOnShutdown12312026/10/06 07:35:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35991/oidc12322026/10/06 07:35:45 INFO Aborted multipart uploads count=0 kept=012332026/10/06 07:35:45 WARN Force mode enabled - objects will be deleted immediately without grace period12342026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures1235--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.45s)1236=== CONT TestService_AuthMiddleware_OIDC12372026/10/06 07:35:45 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=012382026/10/06 07:35:45 INFO Vacuumed table table=pending_closures12392026/10/06 07:35:45 INFO Vacuumed table table=pending_objects12402026/10/06 07:35:45 INFO Vacuumed table table=multipart_uploads12412026/10/06 07:35:45 INFO Vacuumed table table=closures12422026/10/06 07:35:45 INFO Vacuumed table table=objects1243--- PASS: TestGCSweepDeliversEachKeyOnce (0.51s)1244=== CONT TestNARDeduplicationMetadataUploadBug1245--- PASS: TestObjectStatsTrigger (0.45s)1246=== CONT TestService_AuthMiddleware_MTLSProxyHeader12472026/10/06 07:35:45 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161248--- PASS: TestReadProxyNarinfo (0.61s)1249=== CONT TestLeadIncumbentAnnouncesAtOnce12502026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures12512026/10/06 07:35:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34441/oidc12522026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures12532026/10/06 07:35:45 INFO Aborted multipart uploads count=0 kept=012542026/10/06 07:35:45 WARN Force mode enabled - objects will be deleted immediately without grace period12552026/10/06 07:35:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012562026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures12572026/10/06 07:35:45 INFO Vacuumed table table=pending_closures12582026/10/06 07:35:45 INFO Vacuumed table table=pending_objects12592026/10/06 07:35:45 INFO Vacuumed table table=multipart_uploads12602026/10/06 07:35:45 INFO Vacuumed table table=closures12612026/10/06 07:35:45 INFO Vacuumed table table=objects12622026/10/06 07:35:45 INFO Received cleanup request method=DELETE path=/api/pending_closures12632026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures1264--- PASS: TestGCSweepSkipsPendingObjects (0.48s)1265=== CONT TestCreatePendingClosureRejectsOversizedNAR12662026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures1267--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1268=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1269--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.40s)1270=== CONT TestCacheConfigHandlerMaxNarSize1271--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1272=== CONT TestLeadElectsOneAndHandsOver12732026/10/06 07:35:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12742026/10/06 07:35:45 WARN Refused reserved pin name=worker-x86_64-linux12752026/10/06 07:35:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12762026/10/06 07:35:45 INFO Received create pin request method=POST path=/api/pins/my-app12772026/10/06 07:35:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1278--- PASS: TestCreatePin_ReservedPins (0.64s)1279=== CONT TestService_verifyS3Integrity12802026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures1281--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.42s)1282=== CONT TestGenerateLandingPage1283--- PASS: TestGenerateLandingPage (0.00s)1284=== CONT TestUploadHandlersRejectInvalidKeys1285=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1286=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1287=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1288=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1289=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1290=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1291=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1292=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1293=== CONT TestService_readinessHandler12942026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures12952026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures12962026/10/06 07:35:45 INFO Aborted multipart uploads count=0 kept=012972026/10/06 07:35:45 WARN Force mode enabled - objects will be deleted immediately without grace period12982026/10/06 07:35:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012992026/10/06 07:35:45 INFO Vacuumed table table=pending_closures13002026/10/06 07:35:45 INFO Vacuumed table table=pending_objects13012026/10/06 07:35:45 INFO Vacuumed table table=multipart_uploads13022026/10/06 07:35:45 INFO Vacuumed table table=closures13032026/10/06 07:35:45 INFO Vacuumed table table=objects1304--- PASS: TestGCMetrics (0.40s)1305=== CONT TestCompleteMultipartUnregistered13062026/10/06 07:35:45 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"1307--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.32s)1308=== CONT TestConnectWaitsForAPeerMigration13092026/10/06 07:35:45 INFO Aborted multipart uploads count=0 kept=013102026/10/06 07:35:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13112026/10/06 07:35:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1312--- PASS: TestService_NativeMTLS (0.33s)1313=== CONT TestService_ReadAuthMiddleware13142026/10/06 07:35:45 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=013152026/10/06 07:35:45 INFO Vacuumed table table=pending_closures13162026/10/06 07:35:45 INFO Vacuumed table table=pending_objects13172026/10/06 07:35:45 INFO Vacuumed table table=multipart_uploads13182026/10/06 07:35:45 INFO Vacuumed table table=closures13192026/10/06 07:35:45 INFO Vacuumed table table=objects13202026/10/06 07:35:45 INFO Aborted multipart uploads count=0 kept=013212026/10/06 07:35:45 WARN Force mode enabled - objects will be deleted immediately without grace period13222026/10/06 07:35:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013232026/10/06 07:35:45 INFO Vacuumed table table=pending_closures1324--- PASS: TestMetricsInventory (0.36s)1325=== CONT TestService_healthCheckHandler13262026/10/06 07:35:45 INFO Vacuumed table table=pending_objects13272026/10/06 07:35:45 INFO Vacuumed table table=multipart_uploads13282026/10/06 07:35:45 INFO Vacuumed table table=closures13292026/10/06 07:35:45 INFO Vacuumed table table=objects1330--- PASS: TestPushDedupSurvivesConcurrentGC (0.53s)1331=== CONT TestService_createPendingClosureHandler13322026/10/06 07:35:45 INFO lead: acquired remote=192.0.2.1:123413332026/10/06 07:35:45 INFO Received cleanup request method=DELETE path=/api/pending_closures13342026/10/06 07:35:45 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket58/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13352026/10/06 07:35:45 INFO Aborted multipart uploads count=0 kept=113362026/10/06 07:35:45 INFO Received cleanup request method=DELETE path=/api/pending_closures13372026/10/06 07:35:45 INFO Aborted multipart uploads count=1 kept=01338=== NAME TestOrphanedObjectsGC1339 orphaned_objects_gc_test.go:290: GC Test Summary:1340 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1341 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1342 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1343 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1344 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1345--- PASS: TestOrphanedObjectsGC (0.74s)1346=== CONT TestGracefulShutdownDrainsInflight13472026/10/06 07:35:45 INFO Starting HTTP server address=127.0.0.1:3351113482026/10/06 07:35:45 INFO Shutdown signal received, draining in-flight requests timeout=10s1349--- PASS: TestMultipartCleanup (0.50s)1350=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1351=== RUN TestService_RequireScope_OIDC/builder_may_write1352=== PAUSE TestService_RequireScope_OIDC/builder_may_write1353=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1354=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1355=== RUN TestService_RequireScope_OIDC/ops_may_admin1356=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1357=== RUN TestService_RequireScope_OIDC/ops_may_not_write1358=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1359=== RUN TestService_RequireScope_OIDC/reader_may_not_write1360=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1361=== RUN TestService_RequireScope_OIDC/static_token_may_admin1362=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1363=== RUN TestService_RequireScope_OIDC/static_token_may_write1364=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1365=== RUN TestService_RequireScope_OIDC/reader_may_read1366=== PAUSE TestService_RequireScope_OIDC/reader_may_read1367=== RUN TestService_RequireScope_OIDC/writer_implies_read1368=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1369=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1370=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1371=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1372=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1373=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1374=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1375=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1376=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1377=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1378=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1379=== CONT TestService_cleanupPendingClosuresHandler1380--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.29s)1381=== CONT TestGCTaskStore_Fail1382--- PASS: TestGCTaskStore_Fail (0.00s)1383=== CONT TestUploadHandlersRejectOversizedBody13842026/10/06 07:35:45 INFO lead: acquired remote=192.0.2.1:123413852026/10/06 07:35:45 INFO lead: released remote=192.0.2.1:12341386--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.30s)1387=== CONT TestSkippedUploadsHandler13882026/10/06 07:35:45 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001389--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1390=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1391=== NAME TestNARDeduplicationMetadataUploadBug1392 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2949330952/001/store/x9ng66cmjkykrvg9ng04297mky0cnbym-file1.txt1393--- PASS: TestSkippedUploadsHandler (0.00s)1394=== CONT TestIsValidUploadKey1395=== RUN TestIsValidUploadKey/narinfo1396=== PAUSE TestIsValidUploadKey/narinfo1397=== RUN TestIsValidUploadKey/nar_zst1398=== PAUSE TestIsValidUploadKey/nar_zst1399=== RUN TestIsValidUploadKey/nar_xz1400=== PAUSE TestIsValidUploadKey/nar_xz1401=== RUN TestIsValidUploadKey/nar_plain1402=== PAUSE TestIsValidUploadKey/nar_plain1403=== RUN TestIsValidUploadKey/listing1404=== PAUSE TestIsValidUploadKey/listing1405=== RUN TestIsValidUploadKey/build_log1406=== PAUSE TestIsValidUploadKey/build_log1407=== RUN TestIsValidUploadKey/build_log_home-manager_file1408=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1409=== RUN TestIsValidUploadKey/build_log_plus_in_name1410=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1411=== RUN TestIsValidUploadKey/build_log_question_mark1412=== PAUSE TestIsValidUploadKey/build_log_question_mark1413=== RUN TestIsValidUploadKey/build_log_equals1414=== PAUSE TestIsValidUploadKey/build_log_equals1415=== RUN TestIsValidUploadKey/realisation1416=== PAUSE TestIsValidUploadKey/realisation1417=== RUN TestIsValidUploadKey/realisation_plus_in_output1418=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1419=== RUN TestIsValidUploadKey/nix-cache-info1420=== PAUSE TestIsValidUploadKey/nix-cache-info1421=== RUN TestIsValidUploadKey/index.html1422=== PAUSE TestIsValidUploadKey/index.html1423=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1424=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1425=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1426=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1427=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1428=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1429=== RUN TestIsValidUploadKey/traversal1430=== PAUSE TestIsValidUploadKey/traversal1431=== RUN TestIsValidUploadKey/traversal_nar1432=== PAUSE TestIsValidUploadKey/traversal_nar1433=== RUN TestIsValidUploadKey/absolute1434=== PAUSE TestIsValidUploadKey/absolute1435=== RUN TestIsValidUploadKey/empty_key1436=== PAUSE TestIsValidUploadKey/empty_key1437=== RUN TestIsValidUploadKey/unknown_type1438=== PAUSE TestIsValidUploadKey/unknown_type1439=== CONT TestPendingClosureWriteTimeout1440=== RUN TestPendingClosureWriteTimeout/empty1441=== PAUSE TestPendingClosureWriteTimeout/empty1442=== RUN TestPendingClosureWriteTimeout/400_objects1443=== PAUSE TestPendingClosureWriteTimeout/400_objects1444=== RUN TestPendingClosureWriteTimeout/670k_objects1445=== PAUSE TestPendingClosureWriteTimeout/670k_objects1446=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1447=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1448=== CONT TestResolveDBConnectionString1449=== RUN TestResolveDBConnectionString/flag_wins1450=== PAUSE TestResolveDBConnectionString/flag_wins1451=== RUN TestResolveDBConnectionString/file_when_flag_empty1452=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1453=== RUN TestResolveDBConnectionString/missing_file_is_an_error1454=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1455=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1456=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1457=== RUN TestResolveDBConnectionString/nothing_configured1458=== PAUSE TestResolveDBConnectionString/nothing_configured1459=== CONT TestClientFallsBackToClosures1460=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1461=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1462=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1463=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1464=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1465=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1466=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1467=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1468=== CONT TestParseSize1469--- PASS: TestParseSize (0.00s)1470=== CONT TestProxyWriteTimeout1471=== RUN TestProxyWriteTimeout/narinfo1472=== PAUSE TestProxyWriteTimeout/narinfo1473=== RUN TestProxyWriteTimeout/1_GiB_nar1474=== PAUSE TestProxyWriteTimeout/1_GiB_nar1475=== RUN TestProxyWriteTimeout/10_GiB_nar1476=== PAUSE TestProxyWriteTimeout/10_GiB_nar1477=== RUN TestProxyWriteTimeout/unknown_size1478=== PAUSE TestProxyWriteTimeout/unknown_size1479=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock14802026/10/06 07:35:45 INFO lead: acquired remote=192.0.2.1:12341481=== CONT TestService_Rustfstest1482--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.97s)1483=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1484=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1485=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1486=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1487=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1488=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1489=== CONT TestGCTaskStore_PhaseUpdates1490--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1491=== CONT TestGCTaskStore_CompletedAllowsNewTask1492--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1493=== CONT TestGCEndsOnShutdown/before_the_run14942026/10/06 07:35:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14952026/10/06 07:35:45 WARN mTLS auth: bound subjects configured but subject DN unavailable14962026/10/06 07:35:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1497--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.39s)14982026/10/06 07:35:45 INFO Received push request method=POST path=/api/pushes1499=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1500--- PASS: TestGCBugBareHashReferences (0.61s)1501=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15022026/10/06 07:35:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15032026/10/06 07:35:45 INFO Uploading x9ng66cmjkykrvg9ng04297mky0cnbym-file1.txt (160B)15042026/10/06 07:35:45 WARN Failed to register uploaded object key=x9ng66cmjkykrvg9ng04297mky0cnbym.ls error="server returned 404: 404 page not found\n"15052026/10/06 07:35:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15062026/10/06 07:35:45 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15072026/10/06 07:35:45 INFO Signed narinfos id=1 count=115082026/10/06 07:35:45 INFO Uploading 1 narinfos15092026/10/06 07:35:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15102026/10/06 07:35:45 WARN Failed to register uploaded object key=x9ng66cmjkykrvg9ng04297mky0cnbym.narinfo error="server returned 404: 404 page not found\n"15112026/10/06 07:35:45 INFO Upload complete. (120ms)1512=== NAME TestNARDeduplicationMetadataUploadBug1513 metadata_upload_test.go:54: Retrieved narinfo from S3:1514 StorePath: /build/TestNARDeduplicationMetadataUploadBug2949330952/001/store/x9ng66cmjkykrvg9ng04297mky0cnbym-file1.txt1515 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1516 Compression: zstd1517 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1518 NarSize: 1601519 References: 1520 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15212026/10/06 07:35:45 INFO Received uploads request method=POST path=/api/pending_closures1522 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1523 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1524 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15252026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures1526 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2949330952/001/store/g5nydp7d0kvn84f5gkrf3f35isb308vg-file2.txt15272026/10/06 07:35:46 WARN readiness check failed error="closed pool"1528--- PASS: TestService_readinessHandler (0.41s)1529=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15302026/10/06 07:35:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15312026/10/06 07:35:46 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1532--- PASS: TestCompleteMultipartUnregistered (0.37s)1533=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15342026/10/06 07:35:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1535--- PASS: TestService_ReadAuthMiddleware (0.36s)1536=== CONT TestClientErrorHandling/InvalidStorePath15372026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures15382026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures15392026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures15402026/10/06 07:35:46 INFO Received push request method=POST path=/api/pushes15412026/10/06 07:35:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15422026/10/06 07:35:46 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15432026/10/06 07:35:46 INFO Signed narinfos id=2 count=115442026/10/06 07:35:46 WARN Failed to register uploaded object key=g5nydp7d0kvn84f5gkrf3f35isb308vg.ls error="server returned 404: 404 page not found\n"15452026/10/06 07:35:46 INFO Uploading 1 narinfos15462026/10/06 07:35:46 INFO Received complete push request method=POST path=/api/pushes/2/complete15472026/10/06 07:35:46 WARN Failed to register uploaded object key=g5nydp7d0kvn84f5gkrf3f35isb308vg.narinfo error="server returned 404: 404 page not found\n"15482026/10/06 07:35:46 INFO Upload complete. (47ms)1549=== NAME TestNARDeduplicationMetadataUploadBug1550 metadata_upload_test.go:76: Retrieved narinfo from S3:1551 StorePath: /build/TestNARDeduplicationMetadataUploadBug2949330952/001/store/g5nydp7d0kvn84f5gkrf3f35isb308vg-file2.txt1552 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1553 Compression: zstd1554 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1555 NarSize: 1601556 References: 1557 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1558--- PASS: TestService_healthCheckHandler (0.36s)1559=== CONT TestClientErrorHandling/ServerNotAvailable1560=== NAME TestNARDeduplicationMetadataUploadBug1561 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1562 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1563 {"version":1,"root":{"type":"regular","size":44}}1564--- PASS: TestNARDeduplicationMetadataUploadBug (0.61s)1565=== CONT TestClientErrorHandling/InvalidAuthToken15662026/10/06 07:35:46 INFO Received cleanup request method=DELETE path=/api/pending_closures15672026/10/06 07:35:46 INFO Aborted multipart uploads count=0 kept=015682026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures15692026/10/06 07:35:46 INFO Received cleanup request method=DELETE path=/api/pending_closures15702026/10/06 07:35:46 INFO Aborted multipart uploads count=1 kept=015712026/10/06 07:35:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15722026-10-06 07:35:46.138 UTC [1500] ERROR: Closure does not exist: id=115732026-10-06 07:35:46.138 UTC [1500] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE15742026-10-06 07:35:46.138 UTC [1500] STATEMENT: -- name: CommitPendingClosure :exec1575 SELECT commit_pending_closure($1::bigint)1576 1577--- PASS: TestService_cleanupPendingClosuresHandler (0.35s)1578=== CONT TestPush_RejectsBadRequests/no_roots15792026/10/06 07:35:46 INFO Received push request method=POST path=/api/pushes1580=== CONT TestPush_RejectsBadRequests/bad_root15812026/10/06 07:35:46 INFO Received push request method=POST path=/api/pushes1582=== CONT TestPush_RejectsBadRequests/root_not_in_objects15832026/10/06 07:35:46 INFO Received push request method=POST path=/api/pushes1584=== CONT TestPush_RejectsBadRequests/no_objects15852026/10/06 07:35:46 INFO Received push request method=POST path=/api/pushes1586=== CONT TestCacheConfigHandler/full_config,_no_issuer1587--- PASS: TestPush_RejectsBadRequests (0.48s)1588 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1589 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1590 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1591 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1592=== CONT TestCacheConfigHandler/no_signing_keys1593=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1594=== CONT TestCacheConfigHandler/no_cache_url_configured1595--- PASS: TestCacheConfigHandler (0.00s)1596 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1597 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1598 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1599 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1600=== CONT TestIsValidCachePath/narinfo1601=== CONT TestIsValidCachePath/empty1602=== CONT TestIsValidCachePath/random_path1603=== CONT TestIsValidCachePath/invalid_char_u1604=== CONT TestIsValidCachePath/invalid_char_e1605=== CONT TestIsValidCachePath/traversal_in_middle1606=== CONT TestIsValidCachePath/traversal_parent1607=== CONT TestIsValidCachePath/index.html1608=== CONT TestIsValidCachePath/nix-cache-info1609=== CONT TestIsValidCachePath/realisation1610=== CONT TestIsValidCachePath/log1611=== CONT TestIsValidCachePath/ls1612=== CONT TestIsValidCachePath/nar_uncompressed1613=== CONT TestIsValidCachePath/nar_bz21614=== CONT TestIsValidCachePath/nar_xz1615=== CONT TestIsValidCachePath/leading_slash1616=== CONT TestIsValidCachePath/nar_zst1617=== CONT TestIsValidCachePath/wrong_extension1618=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1619=== CONT TestIsValidCachePath/short_hash1620--- PASS: TestIsValidCachePath (0.00s)1621 --- PASS: TestIsValidCachePath/narinfo (0.00s)1622 --- PASS: TestIsValidCachePath/empty (0.00s)1623 --- PASS: TestIsValidCachePath/random_path (0.00s)1624 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1625 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1626 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1627 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1628 --- PASS: TestIsValidCachePath/index.html (0.00s)1629 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1630 --- PASS: TestIsValidCachePath/realisation (0.00s)1631 --- PASS: TestIsValidCachePath/log (0.00s)1632 --- PASS: TestIsValidCachePath/ls (0.00s)1633 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1634 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1635 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1636 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1637 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1638 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1639 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1640 --- PASS: TestIsValidCachePath/short_hash (0.00s)1641=== CONT TestParseSingleRange/none1642=== CONT TestParseSingleRange/start_far_past_EOF1643=== CONT TestParseSingleRange/start_past_EOF1644=== CONT TestParseSingleRange/single_byte1645=== CONT TestParseSingleRange/suffix_exceeds_size1646=== CONT TestParseSingleRange/suffix1647=== CONT TestParseSingleRange/end_clamped_to_size1648=== CONT TestParseSingleRange/open-ended1649=== CONT TestParseSingleRange/closed1650=== CONT TestParseSingleRange/malformed_end_before_start1651=== CONT TestParseSingleRange/malformed_both_empty1652=== CONT TestParseSingleRange/malformed_no_dash1653=== CONT TestParseSingleRange/multi-range_ignored1654=== CONT TestParseSingleRange/unknown_unit1655--- PASS: TestParseSingleRange (0.00s)1656 --- PASS: TestParseSingleRange/none (0.00s)1657 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1658 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1659 --- PASS: TestParseSingleRange/single_byte (0.00s)1660 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1661 --- PASS: TestParseSingleRange/suffix (0.00s)1662 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1663 --- PASS: TestParseSingleRange/open-ended (0.00s)1664 --- PASS: TestParseSingleRange/closed (0.00s)1665 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1666 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1667 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1668 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1669 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1670=== CONT TestServerTLSConfig/no_client_CA1671=== CONT TestServerTLSConfig/not_a_PEM_file16722026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures1673=== CONT TestServerTLSConfig/missing_CA_file1674--- PASS: TestServerTLSConfig (0.00s)1675 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1676 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1677 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1678=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16792026/10/06 07:35:46 INFO Received uploads request method=POST path=/1680=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16812026/10/06 07:35:46 INFO Received complete multipart upload request method=POST path=/1682=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16832026/10/06 07:35:46 INFO Received uploads request method=POST path=/1684=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16852026/10/06 07:35:46 INFO Received request for more parts method=POST path=/1686--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1687 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1688 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1689 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1690 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1691=== CONT TestService_RequireScope_OIDC/builder_may_write1692=== CONT TestService_RequireScope_OIDC/reader_may_read1693=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1694=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read16952026/10/06 07:35:46 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]1696=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1697=== CONT TestService_RequireScope_OIDC/writer_implies_read1698=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1699=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1700=== CONT TestService_RequireScope_OIDC/reader_may_not_write1701=== CONT TestService_RequireScope_OIDC/static_token_may_write1702=== CONT TestService_RequireScope_OIDC/static_token_may_admin1703=== CONT TestService_RequireScope_OIDC/ops_may_admin1704=== CONT TestService_RequireScope_OIDC/ops_may_not_write1705=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1706=== CONT TestIsValidUploadKey/narinfo1707=== CONT TestIsValidUploadKey/unknown_type1708=== CONT TestIsValidUploadKey/empty_key1709=== CONT TestIsValidUploadKey/absolute1710=== CONT TestIsValidUploadKey/traversal_nar1711=== CONT TestIsValidUploadKey/traversal1712=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1713=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1714=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1715=== CONT TestIsValidUploadKey/index.html1716=== CONT TestIsValidUploadKey/nix-cache-info1717=== CONT TestIsValidUploadKey/realisation_plus_in_output1718=== CONT TestIsValidUploadKey/realisation1719=== CONT TestIsValidUploadKey/build_log_equals1720=== CONT TestIsValidUploadKey/build_log_question_mark1721=== CONT TestIsValidUploadKey/build_log_plus_in_name1722=== CONT TestIsValidUploadKey/build_log_home-manager_file1723--- PASS: TestService_RequireScope_OIDC (0.41s)1724 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1725 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1726 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1727 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1728 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1729 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1730 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1731 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1732 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1733 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1734 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1735 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1736 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1737 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1738=== CONT TestIsValidUploadKey/build_log1739=== CONT TestIsValidUploadKey/listing1740=== CONT TestIsValidUploadKey/nar_zst1741=== CONT TestIsValidUploadKey/nar_plain1742=== CONT TestIsValidUploadKey/nar_xz1743--- PASS: TestIsValidUploadKey (0.00s)1744 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1745 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1746 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1747 --- PASS: TestIsValidUploadKey/absolute (0.00s)1748 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1749 --- PASS: TestIsValidUploadKey/traversal (0.00s)1750 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1751 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1752 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1753 --- PASS: TestIsValidUploadKey/index.html (0.00s)1754 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1755 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1756 --- PASS: TestIsValidUploadKey/realisation (0.00s)1757 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1758 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1759 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1760 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1761 --- PASS: TestIsValidUploadKey/build_log (0.00s)1762 --- PASS: TestIsValidUploadKey/listing (0.00s)1763 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1764 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1765 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1766=== CONT TestPendingClosureWriteTimeout/empty1767=== CONT TestPendingClosureWriteTimeout/670k_objects1768=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1769--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.33s)1770=== CONT TestPendingClosureWriteTimeout/400_objects1771=== CONT TestResolveDBConnectionString/flag_wins1772=== CONT TestResolveDBConnectionString/missing_file_is_an_error1773=== CONT TestResolveDBConnectionString/file_when_flag_empty1774=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1775=== CONT TestResolveDBConnectionString/nothing_configured1776=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1777--- PASS: TestResolveDBConnectionString (0.00s)1778 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1779 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1780 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1781 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1782 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1783=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17842026/10/06 07:35:46 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]1785=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1786=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17872026/10/06 07:35:46 WARN Authentication failed token_preview=eyJhbGciOi...ORKqjEjL8g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1788=== CONT TestProxyWriteTimeout/narinfo1789=== CONT TestProxyWriteTimeout/10_GiB_nar1790=== CONT TestProxyWriteTimeout/1_GiB_nar1791=== CONT TestProxyWriteTimeout/unknown_size1792--- PASS: TestProxyWriteTimeout (0.00s)1793 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1794 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1795 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1796 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1797=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17982026/10/06 07:35:46 INFO Received complete multipart upload request method=POST path=/1799--- PASS: TestService_AuthMiddleware_OIDC (0.36s)1800 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1801 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1802 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1803 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1804--- PASS: TestService_Rustfstest (0.28s)1805=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18062026/10/06 07:35:46 INFO Received uploads request method=POST path=/18072026/10/06 07:35:46 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/present1808=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18092026/10/06 07:35:46 INFO Received request for more parts method=POST path=/18102026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures18112026/10/06 07:35:46 INFO Aborted multipart uploads count=0 kept=018122026/10/06 07:35:46 WARN Force mode enabled - objects will be deleted immediately without grace period18132026/10/06 07:35:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.405508ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18142026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures18152026/10/06 07:35:46 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=018162026/10/06 07:35:46 INFO Vacuumed table table=pending_closures18172026/10/06 07:35:46 INFO Vacuumed table table=pending_objects18182026/10/06 07:35:46 INFO Vacuumed table table=multipart_uploads18192026/10/06 07:35:46 INFO Vacuumed table table=closures18202026/10/06 07:35:46 INFO Vacuumed table table=objects18212026/10/06 07:35:46 INFO Aborted multipart uploads count=0 kept=018222026/10/06 07:35:46 WARN Force mode enabled - objects will be deleted immediately without grace period18232026/10/06 07:35:46 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=018242026/10/06 07:35:46 INFO Vacuumed table table=pending_closures18252026/10/06 07:35:46 INFO Vacuumed table table=pending_objects18262026/10/06 07:35:46 INFO Vacuumed table table=multipart_uploads18272026/10/06 07:35:46 INFO Vacuumed table table=closures18282026/10/06 07:35:46 INFO Vacuumed table table=objects18292026/10/06 07:35:46 INFO Aborted multipart uploads count=0 kept=018302026/10/06 07:35:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18312026/10/06 07:35:46 WARN Force mode enabled - objects will be deleted immediately without grace period18322026-10-06 07:35:46.316 UTC [1676] ERROR: canceling statement due to user request18332026-10-06 07:35:46.316 UTC [1676] CONTEXT: PL/pgSQL expression "0"1834 PL/pgSQL function object_stats_apply() line 3 during statement block local variable initialization18352026-10-06 07:35:46.316 UTC [1676] STATEMENT: -- name: MarkStaleObjects :execrows1836 WITH RECURSIVE ct AS (1837 SELECT timezone('UTC', now()) AS now1838 ),1839 closure_reach AS (1840 -- Start with all closure keys1841 SELECT o.key, o.refs1842 FROM objects o1843 INNER JOIN closures c ON o.key = c.key1844 UNION1845 -- Recursively add all referenced objects1846 SELECT o.key, o.refs1847 FROM objects o1848 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1849 ),1850 reachable_objects AS (1851 SELECT DISTINCT key FROM closure_reach1852 ),1853 stale_objects AS (1854 SELECT o.key1855 FROM objects AS o, ct1856 WHERE1857 NOT EXISTS (1858 SELECT 11859 FROM reachable_objects ro1860 WHERE ro.key = o.key1861 )1862 AND NOT EXISTS (1863 SELECT 11864 FROM pending_objects AS po1865 WHERE po.key = o.key1866 )1867 AND o.deleted_at IS NULL -- Only mark fresh objects1868 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1869 FOR UPDATE1870 )1871 UPDATE objects1872 SET1873 deleted_at = ct.now,1874 first_deleted_at = COALESCE(first_deleted_at, ct.now)1875 FROM stale_objects, ct1876 WHERE objects.key = stale_objects.key1877 1878--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1879 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)1880 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.36s)18812026/10/06 07:35:46 INFO Aborted multipart uploads count=0 kept=018822026/10/06 07:35:46 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LjRhZDA4ODNmLTk0NzYtNDBkOC1iMmEyLWIwZTFiNGVkYmEzOXgxNzkxMjcyMTQ2MDA5MTI5NDgw parts=1018832026/10/06 07:35:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18842026/10/06 07:35:46 WARN Force mode enabled - objects will be deleted immediately without grace period18852026/10/06 07:35:46 INFO Completed upload id=118862026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures18872026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures18882026/10/06 07:35:46 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39693/bucket88/?delete=\": context canceled"18892026/10/06 07:35:46 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo18902026/10/06 07:35:46 WARN Found objects in DB but missing from S3, will re-upload count=11891--- PASS: TestGCEndsOnShutdown (0.00s)1892 --- PASS: TestGCEndsOnShutdown/before_the_run (0.27s)1893 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.30s)1894 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.29s)1895--- PASS: TestService_verifyS3Integrity (0.74s)18962026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures18972026/10/06 07:35:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18982026/10/06 07:35:46 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NmE3MWQ2ZTktZTYyZi00Nzg1LTg2OTgtY2MyODc1MGZkZTM0LjkyOWI1MDBlLTg0YzktNDY2My1hN2NjLWUyYTFjOTQ2NGZhNngxNzkxMjcyMTQ2MDg5MjM4MjI5 parts=1018992026/10/06 07:35:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19002026/10/06 07:35:46 INFO Completed upload id=119012026/10/06 07:35:46 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019022026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures19032026/10/06 07:35:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures19042026/10/06 07:35:46 INFO Aborted multipart uploads count=0 kept=019052026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures19062026/10/06 07:35:46 INFO Received uploads request method=POST path=/api/pending_closures19072026/10/06 07:35:46 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19082026/10/06 07:35:46 INFO Uploading 4r457vi2lzk27acx73fw79b683pw4vqn-a (216B)19092026/10/06 07:35:46 INFO Uploading xgsxrdpyzkh4bd5iqadyyzyjcr88xb2n-shared-dep (136B)19102026/10/06 07:35:46 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=019112026/10/06 07:35:46 INFO Vacuumed table table=pending_closures19122026/10/06 07:35:46 WARN Failed to register uploaded object key=30azmdb49c3il91rhxsblkya2qnk7kfg.ls error="server returned 404: 404 page not found\n"19132026/10/06 07:35:46 WARN Failed to register uploaded object key=nar/0d5bpjl6x02pdhzp80k8m3zjbdc2pffalx1v37d9drw7ls1nkn4b.nar.zst error="server returned 404: 404 page not found\n"19142026/10/06 07:35:46 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19152026/10/06 07:35:46 WARN Failed to register uploaded object key=4r457vi2lzk27acx73fw79b683pw4vqn.ls error="server returned 404: 404 page not found\n"19162026/10/06 07:35:46 WARN Failed to register uploaded object key=xgsxrdpyzkh4bd5iqadyyzyjcr88xb2n.ls error="server returned 404: 404 page not found\n"19172026/10/06 07:35:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19182026/10/06 07:35:46 INFO Vacuumed table table=pending_objects19192026/10/06 07:35:46 INFO Signed narinfos id=1 count=219202026/10/06 07:35:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19212026/10/06 07:35:46 INFO Signed narinfos id=2 count=219222026/10/06 07:35:46 INFO Uploading 4 narinfos19232026/10/06 07:35:46 INFO Vacuumed table table=multipart_uploads19242026/10/06 07:35:46 INFO Vacuumed table table=closures19252026/10/06 07:35:46 WARN Failed to register uploaded object key=4r457vi2lzk27acx73fw79b683pw4vqn.narinfo error="server returned 404: 404 page not found\n"19262026/10/06 07:35:46 WARN Failed to register uploaded object key=xgsxrdpyzkh4bd5iqadyyzyjcr88xb2n.narinfo error="server returned 404: 404 page not found\n"19272026/10/06 07:35:46 WARN Failed to register uploaded object key=30azmdb49c3il91rhxsblkya2qnk7kfg.narinfo error="server returned 404: 404 page not found\n"19282026/10/06 07:35:46 INFO Vacuumed table table=objects19292026/10/06 07:35:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19302026/10/06 07:35:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19312026/10/06 07:35:46 WARN Failed to register uploaded object key=xgsxrdpyzkh4bd5iqadyyzyjcr88xb2n.narinfo error="server returned 404: 404 page not found\n"19322026/10/06 07:35:46 INFO Completed upload id=119332026/10/06 07:35:46 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19342026/10/06 07:35:46 INFO Completed upload id=219352026/10/06 07:35:46 INFO Upload complete. (56ms)1936=== NAME TestClientFallsBackToClosures1937 client_pushes_test.go:112: Retrieved narinfo from S3:1938 StorePath: /build/TestClientFallsBackToClosures3671062403/001/store/xgsxrdpyzkh4bd5iqadyyzyjcr88xb2n-shared-dep1939 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1940 Compression: zstd1941 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821942 NarSize: 1361943 References: 1944 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1945 client_pushes_test.go:112: Retrieved narinfo from S3:1946 StorePath: /build/TestClientFallsBackToClosures3671062403/001/store/4r457vi2lzk27acx73fw79b683pw4vqn-a1947 URL: nar/0d5bpjl6x02pdhzp80k8m3zjbdc2pffalx1v37d9drw7ls1nkn4b.nar.zst1948 Compression: zstd1949 NarHash: sha256:0d5bpjl6x02pdhzp80k8m3zjbdc2pffalx1v37d9drw7ls1nkn4b1950 NarSize: 2161951 References: /build/TestClientFallsBackToClosures3671062403/001/store/xgsxrdpyzkh4bd5iqadyyzyjcr88xb2n-shared-dep1952 CA: text:sha256:1281a1m8ymk11c4yrn9hzjsvrbjmqrc1hw7frh15z2km7vksqa901953 client_pushes_test.go:112: Retrieved narinfo from S3:1954 StorePath: /build/TestClientFallsBackToClosures3671062403/001/store/30azmdb49c3il91rhxsblkya2qnk7kfg-b1955 URL: nar/0d5bpjl6x02pdhzp80k8m3zjbdc2pffalx1v37d9drw7ls1nkn4b.nar.zst1956 Compression: zstd1957 NarHash: sha256:0d5bpjl6x02pdhzp80k8m3zjbdc2pffalx1v37d9drw7ls1nkn4b1958 NarSize: 2161959 References: /build/TestClientFallsBackToClosures3671062403/001/store/xgsxrdpyzkh4bd5iqadyyzyjcr88xb2n-shared-dep1960 CA: text:sha256:1281a1m8ymk11c4yrn9hzjsvrbjmqrc1hw7frh15z2km7vksqa901961--- PASS: TestClientFallsBackToClosures (0.60s)19622026/10/06 07:35:46 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001963--- PASS: TestService_createPendingClosureHandler (0.70s)19642026/10/06 07:35:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19652026/10/06 07:35:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=397.324931ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1966--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.71s)1967=== NAME TestOrphanedObjectsGCStressTest1968 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1969 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19702026/10/06 07:35:46 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019712026/10/06 07:35:46 INFO Received create pin request method=POST path=/api/pins/myapp19722026/10/06 07:35:46 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3272337281/001/store/ia9093jnl02zmpq6v5g2qpl0aylwhj16-pinned-file.txt narinfo_key=ia9093jnl02zmpq6v5g2qpl0aylwhj16.narinfo19732026/10/06 07:35:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures19742026/10/06 07:35:46 INFO Garbage collection started19752026/10/06 07:35:46 INFO Aborted multipart uploads count=0 kept=019762026/10/06 07:35:46 WARN Force mode enabled - objects will be deleted immediately without grace period19772026/10/06 07:35:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019782026/10/06 07:35:46 INFO Vacuumed table table=pending_closures19792026/10/06 07:35:46 INFO Vacuumed table table=pending_objects19802026/10/06 07:35:46 INFO Vacuumed table table=multipart_uploads19812026/10/06 07:35:46 INFO Vacuumed table table=closures19822026/10/06 07:35:46 INFO Vacuumed table table=objects19832026/10/06 07:35:46 INFO lead: released remote=192.0.2.1:12341984--- PASS: TestLeadEndsOnShutdown (1.39s)19852026/10/06 07:35:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.215411ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1986=== NAME TestOrphanedObjectsGCStressTest1987 orphaned_objects_gc_test.go:509: Stress test completed successfully:1988 orphaned_objects_gc_test.go:510: - Active objects preserved: 201989 orphaned_objects_gc_test.go:511: - Objects deleted: 2101990 orphaned_objects_gc_test.go:512: - Total GC'd: 2101991--- PASS: TestOrphanedObjectsGCStressTest (1.97s)19922026/10/06 07:35:47 INFO lead: released remote=192.0.2.1:123419932026/10/06 07:35:47 INFO lead: acquired remote=192.0.2.1:123419942026/10/06 07:35:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01995=== NAME TestClientIntegration1996 client_integration_test.go:323: Objects in database after GC:1997 client_integration_test.go:323: Successfully deleted all objects with GC --force1998--- PASS: TestClientIntegration (2.72s)1999--- PASS: TestPendingClosureWriteTimeout (0.00s)2000 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2001 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2002 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2003 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)2004--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2005 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2006 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2007 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.03s)20082026/10/06 07:35:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.464873667s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20092026/10/06 07:35:48 INFO lead: released remote=192.0.2.1:12342010--- PASS: TestLeadElectsOneAndHandsOver (2.66s)2011=== NAME TestPinProtectsFromGC2012 client_integration_test.go:840: Pin successfully protected closure from garbage collection2013--- PASS: TestPinProtectsFromGC (4.66s)20142026/10/06 07:35:49 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-config2015--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.66s)20162026/10/06 07:35:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.150214ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20172026/10/06 07:35:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.108612ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20182026/10/06 07:35:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.137793ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20192026/10/06 07:35:50 WARN Rate limiter enabled after throttle name=s3-test rate=520202026/10/06 07:35:50 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2021=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2022 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102023 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002024--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.28s)20252026/10/06 07:35:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.507796809s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2026--- PASS: TestConnectWaitsForAPeerMigration (5.12s)20272026/10/06 07:35:51 INFO Aborted multipart uploads count=1 kept=020282026/10/06 07:35:51 INFO Received cleanup request method=DELETE path=/api/pending_closures20292026/10/06 07:35:51 INFO Aborted multipart uploads count=1 kept=02030--- PASS: TestPendingCleanupUsesOneCutoff (6.45s)20312026/10/06 07:35:52 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"20322026/10/06 07:35:52 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-config20332026/10/06 07:35:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.878501ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20342026/10/06 07:35:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.330605ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/06 07:35:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.980442ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20362026/10/06 07:35:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.69495224s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/06 07:35:55 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_closures20382026/10/06 07:35:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.19441ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20392026/10/06 07:35:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.160094ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20402026/10/06 07:35:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=750.368006ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20412026/10/06 07:35:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.679849218s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2042--- PASS: TestClientErrorHandling (0.00s)2043 --- PASS: TestClientErrorHandling/InvalidStorePath (0.30s)2044 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.34s)2045 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.27s)2046PASS20472026-10-06 07:35:58.614 UTC [128] LOG: received smart shutdown request20482026-10-06 07:35:58.617 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120492026-10-06 07:35:58.629 UTC [133] LOG: shutting down20502026-10-06 07:35:58.629 UTC [133] LOG: checkpoint starting: shutdown immediate20512026-10-06 07:35:59.594 UTC [133] LOG: checkpoint complete: wrote 10911 buffers (66.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.188 s, sync=0.747 s, total=0.966 s; sync files=31000, longest=0.003 s, average=0.001 s; distance=428480 kB, estimate=428480 kB; lsn=0/1B9D5E38, redo lsn=0/1B9D5E3820522026-10-06 07:35:59.675 UTC [128] LOG: database system is shut down2053Running OIDC tests...2054=== RUN TestAudienceForIssuer2055=== PAUSE TestAudienceForIssuer2056=== RUN TestGlobMatch2057=== PAUSE TestGlobMatch2058=== RUN TestValidateToken_ValidToken2059=== PAUSE TestValidateToken_ValidToken2060=== RUN TestValidateToken_WrongAudience2061=== PAUSE TestValidateToken_WrongAudience2062=== RUN TestValidateToken_Expired2063=== PAUSE TestValidateToken_Expired2064=== RUN TestValidateToken_BoundClaimsMismatch2065=== PAUSE TestValidateToken_BoundClaimsMismatch2066=== RUN TestValidateToken_BoundSubjectMismatch2067=== PAUSE TestValidateToken_BoundSubjectMismatch2068=== RUN TestValidateToken_MultipleProviders2069=== PAUSE TestValidateToken_MultipleProviders2070=== RUN TestValidateToken_NoMatchingProvider2071=== PAUSE TestValidateToken_NoMatchingProvider2072=== RUN TestValidateToken_KubernetesServiceAccount2073=== PAUSE TestValidateToken_KubernetesServiceAccount2074=== RUN TestNewValidator_KubernetesRequiresCA2075=== PAUSE TestNewValidator_KubernetesRequiresCA2076=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2077=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2078=== RUN TestPins_ReservedForMatchingRule2079=== PAUSE TestPins_ReservedForMatchingRule2080=== RUN TestPins_TopLevelShorthand2081=== PAUSE TestPins_TopLevelShorthand2082=== RUN TestPins_ConfigValidation2083=== PAUSE TestPins_ConfigValidation2084=== RUN TestScopes_LegacyProviderDefaultsToWrite2085=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2086=== RUN TestScopes_Rules2087=== PAUSE TestScopes_Rules2088=== RUN TestScopes_ConfigValidation2089=== PAUSE TestScopes_ConfigValidation2090=== CONT TestAudienceForIssuer2091=== CONT TestPins_ConfigValidation2092--- PASS: TestAudienceForIssuer (0.00s)2093=== CONT TestValidateToken_NoMatchingProvider2094=== CONT TestValidateToken_KubernetesServiceAccount2095=== CONT TestScopes_Rules2096=== CONT TestValidateToken_Expired2097=== CONT TestValidateToken_ValidToken2098=== CONT TestGlobMatch2099=== RUN TestGlobMatch/foo_foo2100=== PAUSE TestGlobMatch/foo_foo2101=== CONT TestValidateToken_BoundSubjectMismatch2102=== CONT TestScopes_ConfigValidation2103=== CONT TestValidateToken_MultipleProviders2104=== CONT TestValidateToken_WrongAudience2105=== CONT TestScopes_LegacyProviderDefaultsToWrite2106=== CONT TestValidateToken_BoundClaimsMismatch2107=== CONT TestPins_ReservedForMatchingRule2108=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2109=== RUN TestGlobMatch/foo_bar2110=== PAUSE TestGlobMatch/foo_bar2111=== RUN TestGlobMatch/*_2112=== PAUSE TestGlobMatch/*_2113--- PASS: TestScopes_ConfigValidation (0.00s)2114--- PASS: TestPins_ConfigValidation (0.00s)2115=== CONT TestPins_TopLevelShorthand2116=== RUN TestGlobMatch/*_anything2117=== PAUSE TestGlobMatch/*_anything2118=== RUN TestGlobMatch/foo*_foo2119=== PAUSE TestGlobMatch/foo*_foo2120=== RUN TestGlobMatch/foo*_foobar2121=== PAUSE TestGlobMatch/foo*_foobar2122=== RUN TestGlobMatch/foo*_bar2123=== PAUSE TestGlobMatch/foo*_bar2124=== RUN TestGlobMatch/*bar_bar2125=== PAUSE TestGlobMatch/*bar_bar2126=== CONT TestNewValidator_KubernetesRequiresCA2127=== RUN TestGlobMatch/*bar_foobar2128=== PAUSE TestGlobMatch/*bar_foobar2129=== RUN TestGlobMatch/*bar_foo2130=== PAUSE TestGlobMatch/*bar_foo2131=== RUN TestGlobMatch/foo*bar_foobar2132=== PAUSE TestGlobMatch/foo*bar_foobar2133=== RUN TestGlobMatch/foo*bar_foo123bar2134=== PAUSE TestGlobMatch/foo*bar_foo123bar2135=== RUN TestGlobMatch/foo*bar_foobarbaz2136=== PAUSE TestGlobMatch/foo*bar_foobarbaz2137=== RUN TestGlobMatch/*/*_foo/bar2138=== PAUSE TestGlobMatch/*/*_foo/bar2139=== RUN TestGlobMatch/*/*_foo2140=== PAUSE TestGlobMatch/*/*_foo2141=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2142=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2143=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02144=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02145=== RUN TestGlobMatch/refs/*/main_refs/heads/main2146=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2147=== RUN TestGlobMatch/fo?_foo2148=== PAUSE TestGlobMatch/fo?_foo2149=== RUN TestGlobMatch/fo?_fo2150=== PAUSE TestGlobMatch/fo?_fo2151=== RUN TestGlobMatch/fo?_fooo2152=== PAUSE TestGlobMatch/fo?_fooo2153=== RUN TestGlobMatch/?oo_foo2154=== PAUSE TestGlobMatch/?oo_foo2155=== RUN TestGlobMatch/?oo_boo2156=== PAUSE TestGlobMatch/?oo_boo2157=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2158=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2159=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2160=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2161=== CONT TestGlobMatch/foo_foo2162=== CONT TestGlobMatch/?oo_foo2163=== CONT TestGlobMatch/fo?_fooo2164=== CONT TestGlobMatch/fo?_fo2165=== CONT TestGlobMatch/fo?_foo2166=== CONT TestGlobMatch/refs/*/main_refs/heads/main2167=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02168=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2169=== CONT TestGlobMatch/*/*_foo2170=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2171=== CONT TestGlobMatch/foo*_foobar2172=== CONT TestGlobMatch/foo*_foo2173=== CONT TestGlobMatch/*_anything2174=== CONT TestGlobMatch/*_2175=== CONT TestGlobMatch/foo_bar2176=== CONT TestGlobMatch/?oo_boo2177=== CONT TestGlobMatch/*/*_foo/bar2178=== CONT TestGlobMatch/foo*bar_foobarbaz2179=== CONT TestGlobMatch/foo*bar_foo123bar2180=== CONT TestGlobMatch/foo*bar_foobar2181=== CONT TestGlobMatch/*bar_foo2182=== CONT TestGlobMatch/*bar_foobar2183=== CONT TestGlobMatch/*bar_bar2184=== CONT TestGlobMatch/foo*_bar2185=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2186--- PASS: TestGlobMatch (0.00s)2187 --- PASS: TestGlobMatch/foo_foo (0.00s)2188 --- PASS: TestGlobMatch/?oo_foo (0.00s)2189 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2190 --- PASS: TestGlobMatch/fo?_fo (0.00s)2191 --- PASS: TestGlobMatch/fo?_foo (0.00s)2192 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2193 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2194 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2195 --- PASS: TestGlobMatch/*/*_foo (0.00s)2196 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2197 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2198 --- PASS: TestGlobMatch/foo*_foo (0.00s)2199 --- PASS: TestGlobMatch/*_anything (0.00s)2200 --- PASS: TestGlobMatch/*_ (0.00s)2201 --- PASS: TestGlobMatch/foo_bar (0.00s)2202 --- PASS: TestGlobMatch/?oo_boo (0.00s)2203 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2204 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2205 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2206 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2207 --- PASS: TestGlobMatch/*bar_foo (0.00s)2208 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2209 --- PASS: TestGlobMatch/*bar_bar (0.00s)2210 --- PASS: TestGlobMatch/foo*_bar (0.00s)2211 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)22122026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34073/oidc22132026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40717/oidc22142026/10/06 07:36:01 http: TLS handshake error from 127.0.0.1:60590: remote error: tls: bad certificate2215--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)2216--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)2217--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)22182026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37423/oidc22192026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32857/oidc2220--- PASS: TestValidateToken_ValidToken (0.12s)2221--- PASS: TestScopes_Rules (0.12s)22222026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35415/oidc2223--- PASS: TestPins_ReservedForMatchingRule (0.12s)22242026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39529/oidc2225--- PASS: TestValidateToken_WrongAudience (0.16s)22262026/10/06 07:36:01 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232227--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.17s)22282026/10/06 07:36:01 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:435212229--- PASS: TestValidateToken_KubernetesServiceAccount (0.26s)22302026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35771/oidc2231--- PASS: TestPins_TopLevelShorthand (0.27s)22322026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35191/oidc2233--- PASS: TestValidateToken_BoundSubjectMismatch (0.30s)22342026/10/06 07:36:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43659/oidc2235--- PASS: TestValidateToken_NoMatchingProvider (0.31s)22362026/10/06 07:36:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33873/oidc22372026/10/06 07:36:01 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46401/oidc2238--- PASS: TestValidateToken_MultipleProviders (0.37s)22392026/10/06 07:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45269/oidc2240--- PASS: TestValidateToken_Expired (0.40s)2241PASS2242Running hook tests...2243=== RUN TestSendPathsEmpty2244=== PAUSE TestSendPathsEmpty2245=== RUN TestQueueEnqueueAndFetch2246=== PAUSE TestQueueEnqueueAndFetch2247=== RUN TestQueueDeduplication2248=== PAUSE TestQueueDeduplication2249=== RUN TestQueueRemove2250=== PAUSE TestQueueRemove2251=== RUN TestQueueFetchBatchLimit2252=== PAUSE TestQueueFetchBatchLimit2253=== RUN TestQueueRetryMovesToBack2254=== PAUSE TestQueueRetryMovesToBack2255=== RUN TestQueueFetchRemoveLifecycle2256=== PAUSE TestQueueFetchRemoveLifecycle2257=== RUN TestQueueConcurrentWriters2258=== PAUSE TestQueueConcurrentWriters2259=== RUN TestQueueRemoveLargeClosure2260=== PAUSE TestQueueRemoveLargeClosure2261=== RUN TestServerClientIntegration2262=== PAUSE TestServerClientIntegration2263=== RUN TestServerQueueError2264=== PAUSE TestServerQueueError2265=== RUN TestGetListenerSocketActivation2266 server_test.go:210: === RUN TestGetListenerSocketActivation2267 --- PASS: TestGetListenerSocketActivation (0.00s)2268 PASS2269 2270--- PASS: TestGetListenerSocketActivation (0.01s)2271=== RUN TestDrainIsolatesPoisonPath2272=== PAUSE TestDrainIsolatesPoisonPath2273=== RUN TestRunNotBlockedByPoisonHead2274=== PAUSE TestRunNotBlockedByPoisonHead2275=== RUN TestDrainGivesUpWhenServerDown2276=== PAUSE TestDrainGivesUpWhenServerDown2277=== RUN TestFailedPathPrunedByLaterClosure2278=== PAUSE TestFailedPathPrunedByLaterClosure2279=== RUN TestWorkerUploadsAndRemoves2280=== PAUSE TestWorkerUploadsAndRemoves2281=== RUN TestWorkerSkipsGCdPaths2282=== PAUSE TestWorkerSkipsGCdPaths2283=== RUN TestWorkerPrunesClosureDeps2284=== PAUSE TestWorkerPrunesClosureDeps2285=== RUN TestDrainTimeout2286=== PAUSE TestDrainTimeout2287=== CONT TestSendPathsEmpty2288=== CONT TestRunNotBlockedByPoisonHead2289=== CONT TestWorkerSkipsGCdPaths2290--- PASS: TestSendPathsEmpty (0.00s)2291=== CONT TestQueueRemoveLargeClosure2292=== CONT TestQueueRetryMovesToBack2293=== CONT TestQueueFetchBatchLimit2294=== CONT TestQueueRemove2295=== CONT TestQueueDeduplication2296=== CONT TestQueueFetchRemoveLifecycle2297=== CONT TestDrainIsolatesPoisonPath2298=== CONT TestQueueEnqueueAndFetch2299=== CONT TestServerQueueError2300=== CONT TestServerClientIntegration2301=== CONT TestQueueConcurrentWriters2302=== CONT TestFailedPathPrunedByLaterClosure2303=== CONT TestWorkerUploadsAndRemoves2304=== CONT TestDrainTimeout2305=== CONT TestDrainGivesUpWhenServerDown23062026/10/06 07:36:01 ERROR Failed to queue paths error="permission denied" count=12307=== CONT TestWorkerPrunesClosureDeps2308--- PASS: TestServerClientIntegration (0.00s)2309--- PASS: TestServerQueueError (0.00s)23102026/10/06 07:36:01 INFO Upload queue status pending=223112026/10/06 07:36:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths324235614/002/nonexistent2312--- PASS: TestQueueEnqueueAndFetch (0.01s)23132026/10/06 07:36:01 INFO Uploading batch count=223142026/10/06 07:36:01 INFO Upload queue status pending=323152026/10/06 07:36:01 INFO Uploading batch count=423162026/10/06 07:36:01 INFO Uploading batch count=123172026/10/06 07:36:01 INFO Upload queue status pending=22318--- PASS: TestQueueFetchBatchLimit (0.02s)23192026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=123202026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=423212026/10/06 07:36:01 INFO Uploading batch count=123222026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=12323--- PASS: TestQueueRemove (0.02s)23242026/10/06 07:36:01 INFO Uploading batch count=123252026/10/06 07:36:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2487941332/002/bbb23262026/10/06 07:36:01 INFO Uploading batch count=123272026/10/06 07:36:01 INFO Uploading batch count=223282026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=223292026/10/06 07:36:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1813020809/002/a23302026/10/06 07:36:01 INFO Uploading batch count=22331--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23322026/10/06 07:36:01 INFO Upload queue status pending=223332026/10/06 07:36:01 INFO Uploading batch count=123342026/10/06 07:36:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1813020809/002/b23352026/10/06 07:36:01 INFO Uploading batch count=12336--- PASS: TestQueueDeduplication (0.02s)2337--- PASS: TestQueueRetryMovesToBack (0.02s)23382026/10/06 07:36:01 INFO Uploading batch count=123392026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=123402026/10/06 07:36:01 INFO Uploading batch count=223412026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=223422026/10/06 07:36:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1813020809/002/c23432026/10/06 07:36:01 INFO Uploading batch count=123442026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=123452026/10/06 07:36:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1813020809/002/d23462026/10/06 07:36:01 INFO Uploading batch count=123472026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=123482026/10/06 07:36:01 INFO Uploading batch count=223492026/10/06 07:36:01 ERROR Upload failed error="upload failed" count=223502026/10/06 07:36:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1813020809/002/e23512026/10/06 07:36:01 ERROR Drain finished with paths left in queue remaining=12352--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23532026/10/06 07:36:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1813020809/002/f23542026/10/06 07:36:01 ERROR Drain finished with paths left in queue remaining=102355--- PASS: TestDrainIsolatesPoisonPath (0.02s)2356--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2357--- PASS: TestWorkerSkipsGCdPaths (0.04s)2358--- PASS: TestWorkerPrunesClosureDeps (0.04s)2359--- PASS: TestWorkerUploadsAndRemoves (0.04s)2360--- PASS: TestQueueRemoveLargeClosure (0.14s)2361--- PASS: TestQueueConcurrentWriters (0.16s)23622026/10/06 07:36:01 ERROR Upload failed error="context deadline exceeded" count=223632026/10/06 07:36:01 ERROR Drain finished with paths left in queue remaining=42364--- PASS: TestDrainTimeout (0.21s)23652026/10/06 07:36:02 INFO Uploading batch count=123662026/10/06 07:36:02 INFO Uploading batch count=123672026/10/06 07:36:02 INFO Uploading batch count=123682026/10/06 07:36:02 ERROR Upload failed error="upload failed" count=123692026/10/06 07:36:02 INFO Uploading batch count=123702026/10/06 07:36:02 ERROR Upload failed error="upload failed" count=123712026/10/06 07:36:02 INFO Uploading batch count=123722026/10/06 07:36:02 ERROR Upload failed error="upload failed" count=123732026/10/06 07:36:02 INFO Uploading batch count=123742026/10/06 07:36:02 ERROR Upload failed error="upload failed" count=123752026/10/06 07:36:02 ERROR Drain finished with paths left in queue remaining=12376--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2377PASS2378Running signing tests...2379=== RUN TestExternalSigner2380=== PAUSE TestExternalSigner2381=== RUN TestExternalSignerWrongPublicKey2382=== PAUSE TestExternalSignerWrongPublicKey2383=== RUN TestExternalSignerErrors2384=== PAUSE TestExternalSignerErrors2385=== RUN TestExternalSignerRestartsAfterCrash2386=== PAUSE TestExternalSignerRestartsAfterCrash2387=== RUN TestExternalSignerProgramErrorKeepsProcess2388=== PAUSE TestExternalSignerProgramErrorKeepsProcess2389=== RUN TestExternalSignerClose2390=== PAUSE TestExternalSignerClose2391=== RUN TestExternalSignerRejectsInvalidPublicKey2392=== PAUSE TestExternalSignerRejectsInvalidPublicKey2393=== RUN TestExternalSignerCancellation2394=== PAUSE TestExternalSignerCancellation2395=== RUN TestGenerateFingerprint2396=== PAUSE TestGenerateFingerprint2397=== RUN TestParseSigningKey2398=== PAUSE TestParseSigningKey2399=== RUN TestSign2400=== PAUSE TestSign2401=== RUN TestSignBatch2402=== PAUSE TestSignBatch2403=== RUN TestNilKeyPublicKey2404=== PAUSE TestNilKeyPublicKey2405=== RUN TestSignErrors2406=== PAUSE TestSignErrors2407=== CONT TestExternalSigner2408=== CONT TestExternalSignerCancellation2409=== CONT TestExternalSignerProgramErrorKeepsProcess2410=== CONT TestExternalSignerRejectsInvalidPublicKey2411=== RUN TestExternalSignerRejectsInvalidPublicKey/#002412=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002413=== CONT TestSignErrors2414=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2415=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2416=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2417=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2418=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2419=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2420=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2421=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2422=== CONT TestExternalSignerRejectsInvalidPublicKey/#002423=== CONT TestNilKeyPublicKey2424--- PASS: TestNilKeyPublicKey (0.00s)2425=== CONT TestSignBatch2426=== CONT TestSign2427=== CONT TestParseSigningKey2428=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2429=== RUN TestParseSigningKey/valid_32-byte_key2430=== CONT TestExternalSignerClose2431=== CONT TestExternalSignerErrors2432=== CONT TestExternalSignerRestartsAfterCrash2433=== CONT TestExternalSignerWrongPublicKey2434=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2435=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2436=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2437--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2438 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2439 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2440 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2441 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2442 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2443=== CONT TestGenerateFingerprint2444=== RUN TestGenerateFingerprint/basic_with_references2445=== PAUSE TestGenerateFingerprint/basic_with_references2446=== RUN TestGenerateFingerprint/no_references2447=== PAUSE TestParseSigningKey/valid_32-byte_key2448=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2449=== RUN TestExternalSignerErrors/exit_on_request2450=== PAUSE TestGenerateFingerprint/no_references2451=== PAUSE TestExternalSignerErrors/exit_on_request2452=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2453=== RUN TestExternalSignerErrors/null2454=== PAUSE TestExternalSignerErrors/null2455=== RUN TestExternalSignerErrors/wrong_id2456=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2457=== RUN TestParseSigningKey/no_colon2458=== PAUSE TestParseSigningKey/no_colon2459=== RUN TestParseSigningKey/empty_name2460=== PAUSE TestParseSigningKey/empty_name2461=== RUN TestParseSigningKey/invalid_base642462=== PAUSE TestParseSigningKey/invalid_base642463=== RUN TestParseSigningKey/wrong_length2464=== PAUSE TestParseSigningKey/wrong_length2465=== CONT TestParseSigningKey/valid_32-byte_key2466=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2467=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2468=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2469=== RUN TestGenerateFingerprint/invalid_nar_hash_length2470=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2471=== CONT TestParseSigningKey/empty_name2472=== CONT TestParseSigningKey/wrong_length2473=== CONT TestParseSigningKey/invalid_base642474=== CONT TestParseSigningKey/no_colon2475=== PAUSE TestExternalSignerErrors/wrong_id2476=== RUN TestExternalSignerErrors/unrequested_key2477=== PAUSE TestExternalSignerErrors/unrequested_key2478=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2479=== RUN TestExternalSignerErrors/wrong_signature_name2480=== RUN TestGenerateFingerprint/invalid_store_path_prefix2481=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2482=== RUN TestGenerateFingerprint/invalid_reference_prefix2483=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2484=== CONT TestGenerateFingerprint/basic_with_references2485=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2486=== CONT TestGenerateFingerprint/invalid_nar_hash_length2487=== RUN TestSignErrors/nil_key2488=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2489=== PAUSE TestExternalSignerErrors/wrong_signature_name2490=== RUN TestExternalSignerErrors/invalid_signature_base642491=== PAUSE TestExternalSignerErrors/invalid_signature_base642492=== RUN TestExternalSignerErrors/program_error2493=== PAUSE TestExternalSignerErrors/program_error2494=== RUN TestExternalSignerErrors/invalid_JSON2495=== PAUSE TestExternalSignerErrors/invalid_JSON2496=== RUN TestExternalSignerErrors/wrong_shape2497=== PAUSE TestExternalSignerErrors/wrong_shape2498=== RUN TestExternalSignerErrors/missing_signatures2499=== CONT TestGenerateFingerprint/invalid_reference_prefix2500=== CONT TestGenerateFingerprint/invalid_store_path_prefix2501=== CONT TestGenerateFingerprint/no_references2502--- PASS: TestSign (0.00s)2503--- PASS: TestGenerateFingerprint (0.00s)2504 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2505 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2506 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2507 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2508 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2509 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2510 --- PASS: TestGenerateFingerprint/no_references (0.00s)2511=== PAUSE TestSignErrors/nil_key2512=== RUN TestSignErrors/nil_narinfo2513=== PAUSE TestSignErrors/nil_narinfo2514=== RUN TestSignErrors/invalid_narinfo2515=== PAUSE TestSignErrors/invalid_narinfo2516=== RUN TestSignErrors/canceled2517=== PAUSE TestSignErrors/canceled2518=== CONT TestSignErrors/nil_key2519=== PAUSE TestExternalSignerErrors/missing_signatures2520=== RUN TestExternalSignerErrors/null_signatures2521=== PAUSE TestExternalSignerErrors/null_signatures2522=== RUN TestExternalSignerErrors/missing_signature_name2523=== PAUSE TestExternalSignerErrors/missing_signature_name2524=== RUN TestExternalSignerErrors/wrong_signature_length2525=== PAUSE TestExternalSignerErrors/wrong_signature_length2526=== RUN TestExternalSignerErrors/wrong_signatures_shape2527=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2528=== RUN TestExternalSignerErrors/too_few_signatures2529=== PAUSE TestExternalSignerErrors/too_few_signatures2530=== RUN TestExternalSignerErrors/exit_at_startup2531=== PAUSE TestExternalSignerErrors/exit_at_startup2532--- PASS: TestParseSigningKey (0.00s)2533 --- PASS: TestParseSigningKey/empty_name (0.00s)2534 --- PASS: TestParseSigningKey/wrong_length (0.00s)2535 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2536 --- PASS: TestParseSigningKey/no_colon (0.00s)2537 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2538 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2539=== CONT TestExternalSignerErrors/wrong_signatures_shape2540=== CONT TestSignErrors/invalid_narinfo2541=== CONT TestExternalSignerErrors/missing_signatures2542=== CONT TestSignErrors/canceled2543=== CONT TestSignErrors/nil_narinfo2544=== CONT TestExternalSignerErrors/exit_on_request2545=== CONT TestExternalSignerErrors/invalid_JSON2546=== CONT TestExternalSignerErrors/program_error2547=== CONT TestExternalSignerErrors/invalid_signature_base642548=== CONT TestExternalSignerErrors/wrong_signature_name2549=== CONT TestExternalSignerErrors/unrequested_key2550=== CONT TestExternalSignerErrors/wrong_id2551=== CONT TestExternalSignerErrors/null2552=== CONT TestExternalSignerErrors/wrong_signature_length2553=== CONT TestExternalSignerErrors/exit_at_startup2554=== CONT TestExternalSignerErrors/too_few_signatures2555=== CONT TestExternalSignerErrors/null_signatures2556=== CONT TestExternalSignerErrors/missing_signature_name2557--- PASS: TestSignBatch (0.00s)2558--- PASS: TestSignErrors (0.00s)2559 --- PASS: TestSignErrors/nil_key (0.00s)2560 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2561 --- PASS: TestSignErrors/canceled (0.00s)2562 --- PASS: TestSignErrors/nil_narinfo (0.00s)2563=== CONT TestExternalSignerErrors/wrong_shape2564--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2565--- PASS: TestExternalSignerWrongPublicKey (0.01s)2566--- PASS: TestExternalSignerClose (0.01s)2567--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2568--- PASS: TestExternalSignerErrors (0.00s)2569 --- PASS: TestExternalSignerErrors/program_error (0.00s)2570 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2571 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2572 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2573 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2574 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2575 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2576 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2577 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2578 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2579 --- PASS: TestExternalSignerErrors/null (0.01s)2580 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2581 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2582 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2583 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2584 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2585--- PASS: TestExternalSigner (0.01s)2586--- PASS: TestExternalSignerCancellation (0.02s)2587PASS2588Running OpenBao signer tests...2589=== RUN TestSign2590=== PAUSE TestSign2591=== RUN TestSignErrors2592=== PAUSE TestSignErrors2593=== RUN TestServe2594=== PAUSE TestServe2595=== RUN TestServeRejectsGarbage2596=== PAUSE TestServeRejectsGarbage2597=== CONT TestSign2598=== CONT TestServeRejectsGarbage2599=== CONT TestSignErrors2600=== RUN TestSignErrors/http_error2601--- PASS: TestServeRejectsGarbage (0.00s)2602=== CONT TestServe2603=== PAUSE TestSignErrors/http_error2604=== RUN TestSignErrors/invalid_json2605=== PAUSE TestSignErrors/invalid_json2606=== RUN TestSignErrors/no_prefix2607=== PAUSE TestSignErrors/no_prefix2608=== RUN TestSignErrors/invalid_base642609=== PAUSE TestSignErrors/invalid_base642610=== CONT TestSignErrors/http_error2611=== CONT TestSignErrors/no_prefix2612=== CONT TestSignErrors/invalid_base642613--- PASS: TestServe (0.00s)2614=== CONT TestSignErrors/invalid_json2615--- PASS: TestSign (0.00s)2616--- PASS: TestSignErrors (0.00s)2617 --- PASS: TestSignErrors/invalid_json (0.00s)2618 --- PASS: TestSignErrors/invalid_base64 (0.00s)2619 --- PASS: TestSignErrors/no_prefix (0.00s)2620 --- PASS: TestSignErrors/http_error (0.00s)2621PASS