niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #357
· 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.11s)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 TestSetClientTLSErrors101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestStreamPushIsolatesFailures103=== CONT TestStreamPushBatchesUnderLoad104=== CONT TestStreamPushReportsEveryPath105=== CONT TestShellSplitErrors106--- PASS: TestShellSplitErrors (0.00s)107=== CONT TestRateLimiterFeedback108=== RUN TestRateLimiterFeedback/429_enables_limiter109=== PAUSE TestRateLimiterFeedback/429_enables_limiter110=== RUN TestRateLimiterFeedback/503_enables_limiter111=== PAUSE TestRateLimiterFeedback/503_enables_limiter112=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter113=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter114=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter115=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1162026/10/05 11:18:35 ERROR Upload failed error="bad path" count=3117=== CONT TestShellSplit118=== CONT TestStreamPushRequestLine119--- PASS: TestShellSplit (0.00s)120=== CONT TestPathInfoCACompatibility121=== CONT TestClientSignaturesByStorePath122--- PASS: TestClientSignaturesByStorePath (0.00s)123=== CONT TestParsePathInfoJSONMultiplePaths124=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths126=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths127=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths128=== CONT TestParsePathInfoJSON129=== RUN TestParsePathInfoJSON/Nix_format130=== PAUSE TestParsePathInfoJSON/Nix_format131=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1322026/10/05 11:18:35 ERROR Upload failed error=boom count=1133=== CONT TestSetClientTLS134=== CONT TestScriptTokenCachesUntilRefresh135=== CONT TestUploadMultipart_PartsInParallel136=== CONT TestScriptTokenEmptyCommand137=== CONT TestDumpPathMatchesNix138=== CONT TestScriptTokenScriptFails139=== CONT TestScriptTokenBadJSON140=== CONT TestScriptTokenEmptyToken141=== CONT TestFileTokenMissing142=== CONT TestScriptTokenNoExpiryRerunsEveryCall1432026/10/05 11:18:35 WARN Rate limiter enabled after throttle name=server-test rate=5144=== CONT TestFileTokenEmpty1452026/10/05 11:18:35 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42687146=== CONT TestGetStorePathHash147=== CONT TestEncodeNixBase32148=== RUN TestEncodeNixBase32/test_string_hash149=== CONT TestStreamPushGivesUpOnDeadServer150=== CONT TestResolveStorePath151=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess152=== CONT TestStreamPushReportsSignatures153=== RUN TestPathInfoCACompatibility/null_ca_field154=== RUN TestParsePathInfoJSON/Lix_format155--- PASS: TestStreamPushReportsEveryPath (0.00s)156=== CONT TestPathInfoHashCompatibility157=== RUN TestSetClientTLSErrors/missing_cert_file158=== RUN TestSetClientTLS/rejects_connection_without_client_cert159=== RUN TestGetStorePathHash/valid_store_path1602026/10/05 11:18:35 ERROR Upload failed error="connection refused" count=20161=== PAUSE TestSetClientTLSErrors/missing_cert_file1622026/10/05 11:18:35 ERROR Server seems unavailable, giving up on batch untried=17163=== PAUSE TestGetStorePathHash/valid_store_path164=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1652026/10/05 11:18:35 WARN Rate limiter backed off name=server-test rate=51662026/10/05 11:18:35 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42687167=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon169=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon170=== CONT TestConvertHashToNix321712026/10/05 11:18:35 WARN Rate limiter enabled after throttle name=server-test rate=5172=== RUN TestConvertHashToNix32/SRI_format_to_Nix32173=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1742026/10/05 11:18:35 ERROR Upload failed error=boom count=1175=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error176=== CONT TestFileTokenReadsAndCaches177=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error178=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error179=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error180=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error181=== CONT TestDumpPathSingleFile182=== CONT TestFilterOversizedClosures183=== RUN TestFilterOversizedClosures/no_limit_keeps_everything184=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything185=== RUN TestSetClientTLSErrors/missing_key_file186=== CONT TestCaseHackSuffix187=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI188=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI189=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512190=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512191=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert192=== CONT TestDumpPathWriterError193=== PAUSE TestParsePathInfoJSON/Lix_format194=== RUN TestParsePathInfoJSON/empty_input195=== PAUSE TestPathInfoCACompatibility/null_ca_field196--- PASS: TestStreamPushIsolatesFailures (0.00s)197--- PASS: TestScriptTokenEmptyCommand (0.00s)198=== CONT TestUploadMultipart_SupersededByPeer199=== PAUSE TestEncodeNixBase32/test_string_hash200=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32201=== RUN TestConvertHashToNix32/already_Nix32_format202=== PAUSE TestConvertHashToNix32/already_Nix32_format203=== RUN TestConvertHashToNix32/invalid_format204=== PAUSE TestConvertHashToNix32/invalid_format205=== CONT TestEncodeNixBase32WithRealHash206=== CONT TestRegisterUploadedObjectReusesConnections207=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun208=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica209=== CONT TestRateLimiterFeedback/429_enables_limiter210=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter211=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped212=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== RUN TestFilterOversizedClosures/all_closures_skipped214=== PAUSE TestFilterOversizedClosures/all_closures_skipped215=== PAUSE TestSetClientTLSErrors/missing_key_file216=== RUN TestSetClientTLSErrors/missing_ca_file217=== PAUSE TestSetClientTLSErrors/missing_ca_file218=== RUN TestSetClientTLSErrors/invalid_ca_file219=== PAUSE TestSetClientTLSErrors/invalid_ca_file220=== CONT TestRateLimiterFeedback/503_enables_limiter221=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter222=== CONT TestPartSizeForNAR223=== RUN TestPartSizeForNAR/zero_stays_at_minimum224=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum225=== RUN TestPartSizeForNAR/small_stays_at_minimum226=== PAUSE TestPartSizeForNAR/small_stays_at_minimum227=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum228=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum229=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts230=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts231=== RUN TestPartSizeForNAR/1_TiB232=== PAUSE TestPartSizeForNAR/1_TiB233=== RUN TestPartSizeForNAR/5_TiB_S3_max_object234=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object235=== RUN TestPartSizeForNAR/capped_at_5_GiB236=== PAUSE TestPartSizeForNAR/capped_at_5_GiB237=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA238=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA239=== RUN TestSetClientTLS/preserves_debug_logging_transport240=== PAUSE TestSetClientTLS/preserves_debug_logging_transport241=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2422026/10/05 11:18:35 WARN Rate limiter enabled after throttle name=server-test rate=52432026/10/05 11:18:35 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:40757244=== CONT TestGetStorePathHash/valid_store_path2452026/10/05 11:18:35 INFO Garbage collection started246=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error2472026/10/05 11:18:35 WARN Rate limiter enabled after throttle name=server-test rate=5248=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2492026/10/05 11:18:35 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:45263250=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122512026/10/05 11:18:35 INFO Garbage collection started252=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon2532026/10/05 11:18:35 WARN Rate limiter backed off name=server-test rate=5254=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI255=== CONT TestConvertHashToNix32/SRI_format_to_Nix322562026/10/05 11:18:35 WARN Rate limiter backed off name=server-test rate=5257=== CONT TestConvertHashToNix32/invalid_format258=== CONT TestConvertHashToNix32/already_Nix32_format259=== CONT TestFilterOversizedClosures/no_limit_keeps_everything260=== CONT TestSetClientTLSErrors/invalid_ca_file261=== CONT TestSetClientTLSErrors/missing_ca_file262=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error263=== CONT TestSetClientTLSErrors/missing_key_file264=== CONT TestPartSizeForNAR/zero_stays_at_minimum265=== CONT TestSetClientTLS/rejects_connection_without_client_cert266=== CONT TestGetStorePathHash/basename_without_hyphen_should_error267=== CONT TestPartSizeForNAR/small_stays_at_minimum268=== CONT TestPartSizeForNAR/capped_at_5_GiB269=== CONT TestPartSizeForNAR/5_TiB_S3_max_object270=== CONT TestPartSizeForNAR/1_TiB271=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts272=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum273=== CONT TestSetClientTLS/preserves_debug_logging_transport274=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2752026/10/05 11:18:35 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0276=== CONT TestFilterOversizedClosures/all_closures_skipped2772026/10/05 11:18:35 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=50278=== CONT TestSetClientTLSErrors/missing_cert_file279=== RUN TestPathInfoCACompatibility/old_string_format_-_text280=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text281=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive282=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive283=== RUN TestPathInfoCACompatibility/new_structured_format_-_text284=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text285=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method286=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method287=== CONT TestPathInfoCACompatibility/null_ca_field288=== CONT TestPathInfoCACompatibility/new_structured_format_-_text289=== CONT TestPathInfoCACompatibility/old_string_format_-_text290--- PASS: TestFileTokenMissing (0.00s)291--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)292--- PASS: TestScriptTokenScriptFails (0.03s)293--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)294--- PASS: TestDoServerRequestAttachesToken (0.04s)295=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== RUN TestUploadMultipart_SupersededByPeer/exists297=== PAUSE TestUploadMultipart_SupersededByPeer/exists298=== RUN TestUploadMultipart_SupersededByPeer/missing299=== PAUSE TestUploadMultipart_SupersededByPeer/missing300=== CONT TestUploadMultipart_SupersededByPeer/exists301=== RUN TestEncodeNixBase32/empty_input302=== PAUSE TestEncodeNixBase32/empty_input303=== CONT TestEncodeNixBase32/test_string_hash304--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)305--- PASS: TestStreamPushReportsSignatures (0.00s)306--- PASS: TestScriptTokenEmptyToken (0.03s)307--- PASS: TestScriptTokenBadJSON (0.03s)308--- PASS: TestFileTokenEmpty (0.00s)309--- PASS: TestEncodeNixBase32WithRealHash (0.00s)310--- PASS: TestFileTokenReadsAndCaches (0.00s)311--- PASS: TestResolveStorePath (0.00s)312=== CONT TestStaticToken313--- PASS: TestStaticToken (0.00s)314=== PAUSE TestParsePathInfoJSON/empty_input315=== CONT TestUploadMultipart_SupersededByPeer/missing316--- PASS: TestPathInfoHashCompatibility (0.00s)317 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)318 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)319 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)320 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)321--- PASS: TestConvertHashToNix32 (0.00s)322 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)323 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)324 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)325--- PASS: TestRateLimiterFeedback (0.00s)326 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)327 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)328 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)329 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)330--- PASS: TestGetStorePathHash (0.00s)331 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)332 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)333 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)334 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)335--- PASS: TestPartSizeForNAR (0.00s)336 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)337 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)338 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)339 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)340 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)341 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)342 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)343--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)344--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3452026/10/05 11:18:35 WARN Garbage collection finished on another replica. Its statistics are not available here346=== RUN TestParsePathInfoJSON/whitespace_only347=== PAUSE TestParsePathInfoJSON/whitespace_only348=== RUN TestParsePathInfoJSON/invalid_JSON349=== PAUSE TestParsePathInfoJSON/invalid_JSON350=== CONT TestParsePathInfoJSON/Nix_format351=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3522026/10/05 11:18:35 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000353=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive354=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths355=== CONT TestEncodeNixBase32/empty_input356--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)357=== CONT TestParsePathInfoJSON/invalid_JSON358=== CONT TestParsePathInfoJSON/whitespace_only359=== CONT TestParsePathInfoJSON/empty_input360=== CONT TestParsePathInfoJSON/Lix_format361--- PASS: TestParsePathInfoJSON (0.04s)362 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)363 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)364 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)365 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)366 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)367--- PASS: TestFilterOversizedClosures (0.00s)368 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)369 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)370 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)371--- PASS: TestSetClientTLSErrors (0.04s)372 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)374 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)375 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)376--- PASS: TestPathInfoCACompatibility (0.04s)377 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)379 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)381 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)382--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)383 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)384 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)385--- PASS: TestEncodeNixBase32 (0.01s)386 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)387 --- PASS: TestEncodeNixBase32/empty_input (0.00s)388--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)389 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)390 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)391--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)3922026/10/05 11:18:35 http: TLS handshake error from 127.0.0.1:46712: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.04s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestStreamPushRequestLine (0.06s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)399--- PASS: TestCaseHackSuffix (0.03s)400--- PASS: TestDumpPathSingleFile (0.03s)401--- PASS: TestDumpPathWriterError (0.05s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.12s)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/postgres2244576747/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/postgres2244576747/data -l logfile start434435/build/postgres2244576747:5432 - no response4362026-10-05 11:18:37.867 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-05 11:18:37.868 UTC [129] LOG: listening on Unix socket "/build/postgres2244576747/.s.PGSQL.5432"4382026-10-05 11:18:37.872 UTC [136] LOG: database system was shut down at 2026-10-05 11:18:37 UTC4392026-10-05 11:18:37.875 UTC [129] LOG: database system is ready to accept connections440/build/postgres2244576747: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/05 11:18:38 INFO lead: acquired remote=192.0.2.1:12344872026/10/05 11:18:38 INFO lead: released remote=192.0.2.1:12344882026/10/05 11:18:39 INFO lead: acquired remote=192.0.2.1:12344892026/10/05 11:18:40 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.94s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/05 11:18:40 INFO lead: acquired remote=192.0.2.1:12344972026-10-05 11:18:41.635 UTC [384] FATAL: terminating connection due to administrator command4982026/10/05 11:18:41 INFO lead: acquired remote=192.0.2.1:12344992026/10/05 11:18:42 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/05 11:18:42 INFO lead: released remote=192.0.2.1:12345012026/10/05 11:18:43 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)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/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/05 11:18:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/05 11:18:43 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 TestPendingClosureWriteTimeout690=== CONT TestPresignedUploadRegisteredBeforeCommit691=== CONT TestForceGCDuringPushOffersSweptObject692=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows693=== CONT TestProxyWriteTimeout694=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle695=== CONT TestSkippedUploadsHandler696=== CONT TestParseSize697--- PASS: TestParseSize (0.00s)698=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection699=== CONT TestGCTaskStore_CompletedAllowsNewTask700--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)701=== CONT TestGCTaskStore_GetReturnsLatest702--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)703=== CONT TestGCTaskStore_GetEmpty704=== CONT TestGCTaskStore_ConflictDifferentParams705=== CONT TestGCTaskStore_DeduplicateSameParams706=== CONT TestGCTaskStore_StartNew707=== CONT TestGCEndsOnShutdown708=== CONT TestCommitRacingPendingCleanupKeepsObjects709=== CONT TestPushWaitsForSweepHoldingRow710=== CONT TestSweepRechecksPendingAfterLocking711=== CONT TestGetExistingObjectsLocksRows712=== CONT TestGCTaskStore_PhaseUpdates713=== CONT TestRegisterCompletedObjectNeedsPendingRow714=== CONT TestSweepSkipsRowsLockedByPush715=== CONT TestService_Rustfstest716=== CONT TestFailedS3DeleteKeepsTombstone717=== RUN TestPendingClosureWriteTimeout/empty718=== CONT TestService_AuthMiddleware719=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows7202026/10/05 11:18:43 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000721=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check722=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check723=== CONT TestGCAdvisoryLockBlocksConcurrentRun724=== PAUSE TestPendingClosureWriteTimeout/empty725=== RUN TestPendingClosureWriteTimeout/400_objects726=== PAUSE TestPendingClosureWriteTimeout/400_objects727=== CONT TestGCMetrics728=== RUN TestProxyWriteTimeout/narinfo729--- PASS: TestGCTaskStore_GetEmpty (0.00s)730--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)731=== CONT TestGCSweepSkipsPendingObjects732=== CONT TestGCSweepDeliversEachKeyOnce733=== CONT TestDeduplicatedObjectsRecordedAsPending734=== CONT TestPushDedupSurvivesConcurrentGC735=== RUN TestGCEndsOnShutdown/before_the_run736=== RUN TestPendingClosureWriteTimeout/670k_objects737=== CONT TestGCBugBareHashReferences738=== PAUSE TestProxyWriteTimeout/narinfo739=== RUN TestProxyWriteTimeout/1_GiB_nar740=== PAUSE TestProxyWriteTimeout/1_GiB_nar741=== RUN TestProxyWriteTimeout/10_GiB_nar742=== PAUSE TestProxyWriteTimeout/10_GiB_nar743=== RUN TestProxyWriteTimeout/unknown_size744=== PAUSE TestProxyWriteTimeout/unknown_size745=== CONT TestLeadEndsOnShutdown746=== CONT TestTombstonedObjectOfferedWithoutWaiting747=== PAUSE TestGCEndsOnShutdown/before_the_run748=== PAUSE TestPendingClosureWriteTimeout/670k_objects749=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline750=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete751=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete752--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)753=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline754=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark755--- PASS: TestGCTaskStore_StartNew (0.00s)756--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)757=== CONT TestLeadIncumbentAnnouncesAtOnce758=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark759=== CONT TestLeadElectsOneAndHandsOver760--- PASS: TestSkippedUploadsHandler (0.01s)761=== CONT TestConnectWaitsForAPeerMigration762--- PASS: TestGetExistingObjectsLocksRows (0.31s)763=== CONT TestResolveDBConnectionString764=== RUN TestResolveDBConnectionString/flag_wins765=== PAUSE TestResolveDBConnectionString/flag_wins766=== RUN TestResolveDBConnectionString/file_when_flag_empty767=== PAUSE TestResolveDBConnectionString/file_when_flag_empty768=== RUN TestResolveDBConnectionString/missing_file_is_an_error769=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error770=== RUN TestResolveDBConnectionString/PGHOST_allows_empty771=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty772=== RUN TestResolveDBConnectionString/nothing_configured773=== PAUSE TestResolveDBConnectionString/nothing_configured774=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock7752026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures7762026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=07772026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period7782026/10/05 11:18:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07792026/10/05 11:18:43 INFO Vacuumed table table=pending_closures7802026/10/05 11:18:43 INFO Vacuumed table table=pending_objects7812026/10/05 11:18:43 INFO Vacuumed table table=multipart_uploads7822026/10/05 11:18:43 INFO Vacuumed table table=closures7832026/10/05 11:18:43 INFO Vacuumed table table=objects784--- PASS: TestService_Rustfstest (0.34s)785=== CONT TestClientFallsBackToClosures786--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.34s)787=== CONT TestClientPushesUseOnePush7882026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures7892026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures7902026/10/05 11:18:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7912026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=07922026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period7932026/10/05 11:18:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7942026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures7952026/10/05 11:18:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07962026/10/05 11:18:43 INFO Vacuumed table table=pending_closures7972026/10/05 11:18:43 INFO Vacuumed table table=pending_objects7982026/10/05 11:18:43 INFO Vacuumed table table=multipart_uploads7992026/10/05 11:18:43 INFO Vacuumed table table=closures8002026/10/05 11:18:43 INFO Vacuumed table table=objects801--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.42s)802=== CONT TestPinProtectsFromGC803--- PASS: TestGCMetrics (0.42s)804=== CONT TestClientSharedPathCommittedMidPush8052026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures8062026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=08072026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period8082026/10/05 11:18:43 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8092026/10/05 11:18:43 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."810--- PASS: TestFailedS3DeleteKeepsTombstone (0.47s)811=== CONT TestClientWithDependencies8122026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures813--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.49s)814=== CONT TestClientMultipleUploads8152026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=08162026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period8172026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures8182026/10/05 11:18:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08192026/10/05 11:18:43 INFO Vacuumed table table=pending_closures8202026/10/05 11:18:43 INFO Vacuumed table table=pending_objects8212026/10/05 11:18:43 INFO Vacuumed table table=multipart_uploads8222026/10/05 11:18:43 INFO Vacuumed table table=closures8232026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=08242026/10/05 11:18:43 INFO Vacuumed table table=objects825--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)826=== CONT TestClientIntegration8272026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period8282026/10/05 11:18:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08292026/10/05 11:18:43 INFO Vacuumed table table=pending_closures8302026/10/05 11:18:43 INFO Vacuumed table table=pending_objects8312026/10/05 11:18:43 INFO Vacuumed table table=multipart_uploads8322026/10/05 11:18:43 INFO Vacuumed table table=closures8332026/10/05 11:18:43 INFO Vacuumed table table=objects834--- PASS: TestGCSweepSkipsPendingObjects (0.55s)835=== CONT TestClientErrorHandling836=== RUN TestClientErrorHandling/InvalidStorePath837=== PAUSE TestClientErrorHandling/InvalidStorePath838=== RUN TestClientErrorHandling/InvalidAuthToken839=== PAUSE TestClientErrorHandling/InvalidAuthToken840=== RUN TestClientErrorHandling/ServerNotAvailable841=== PAUSE TestClientErrorHandling/ServerNotAvailable842=== CONT TestClientCADerivations8432026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=08442026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period8452026/10/05 11:18:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08462026/10/05 11:18:43 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"847--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.57s)848=== CONT TestCacheStatsHandler8492026/10/05 11:18:43 INFO Vacuumed table table=pending_closures8502026/10/05 11:18:43 INFO Vacuumed table table=pending_objects8512026/10/05 11:18:43 INFO Vacuumed table table=multipart_uploads8522026/10/05 11:18:43 INFO Vacuumed table table=closures8532026/10/05 11:18:43 INFO Vacuumed table table=objects8542026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=08552026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period856--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.58s)857=== CONT TestCacheConfigHandler858=== RUN TestCacheConfigHandler/full_config,_no_issuer859=== PAUSE TestCacheConfigHandler/full_config,_no_issuer860=== RUN TestCacheConfigHandler/no_cache_url_configured861=== PAUSE TestCacheConfigHandler/no_cache_url_configured862=== RUN TestCacheConfigHandler/no_signing_keys863=== PAUSE TestCacheConfigHandler/no_signing_keys864=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator865=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator866=== CONT TestService_ReadScope_PublicByDefault8672026/10/05 11:18:43 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=08682026/10/05 11:18:43 INFO Vacuumed table table=pending_closures8692026/10/05 11:18:43 INFO Vacuumed table table=pending_objects8702026/10/05 11:18:43 INFO Vacuumed table table=multipart_uploads8712026/10/05 11:18:43 INFO Vacuumed table table=closures8722026/10/05 11:18:43 INFO Received uploads request method=POST path=/api/pending_closures8732026/10/05 11:18:43 INFO Vacuumed table table=objects874--- PASS: TestSweepSkipsRowsLockedByPush (0.60s)875=== CONT TestService_RequireScope_OIDC876--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.60s)877=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT8782026/10/05 11:18:43 INFO Aborted multipart uploads count=0 kept=08792026/10/05 11:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period880--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.66s)881=== CONT TestCompleteMultipartUnregistered8822026/10/05 11:18:43 INFO lead: acquired remote=192.0.2.1:12348832026/10/05 11:18:43 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=08842026/10/05 11:18:43 INFO Vacuumed table table=pending_closures8852026/10/05 11:18:43 INFO Vacuumed table table=pending_objects8862026/10/05 11:18:43 INFO Vacuumed table table=multipart_uploads8872026/10/05 11:18:43 INFO Vacuumed table table=closures8882026/10/05 11:18:43 INFO Vacuumed table table=objects889--- PASS: TestGCSweepDeliversEachKeyOnce (0.68s)890=== CONT TestService_verifyS3Integrity8912026/10/05 11:18:43 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"892--- PASS: TestService_AuthMiddleware (0.69s)893=== CONT TestService_createPendingClosureHandler8942026/10/05 11:18:43 INFO lead: acquired remote=192.0.2.1:12348952026/10/05 11:18:43 INFO lead: released remote=192.0.2.1:1234896--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.71s)897=== CONT TestService_AuthMiddleware_OIDC8982026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures8992026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures9002026/10/05 11:18:44 INFO lead: acquired remote=192.0.2.1:12349012026/10/05 11:18:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44769/oidc9022026/10/05 11:18:44 INFO Aborted multipart uploads count=0 kept=09032026/10/05 11:18:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45959/oidc9042026/10/05 11:18:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09052026/10/05 11:18:44 INFO Vacuumed table table=pending_closures9062026/10/05 11:18:44 INFO Vacuumed table table=pending_objects9072026/10/05 11:18:44 INFO Vacuumed table table=multipart_uploads9082026/10/05 11:18:44 INFO Vacuumed table table=closures9092026/10/05 11:18:44 INFO Vacuumed table table=objects9102026/10/05 11:18:44 INFO Aborted multipart uploads count=0 kept=09112026/10/05 11:18:44 WARN Force mode enabled - objects will be deleted immediately without grace period9122026/10/05 11:18: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=09132026/10/05 11:18:44 INFO Vacuumed table table=pending_closures9142026/10/05 11:18:44 INFO Vacuumed table table=pending_objects9152026/10/05 11:18:44 INFO Vacuumed table table=multipart_uploads9162026/10/05 11:18:44 INFO Vacuumed table table=closures9172026/10/05 11:18:44 INFO Vacuumed table table=objects918--- PASS: TestPushDedupSurvivesConcurrentGC (0.87s)919=== CONT TestUploadHandlersRejectInvalidKeys920=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info921=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info922=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal923=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal924=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key925=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key926=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key927=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key928=== CONT TestService_ReadAuthMiddleware929--- PASS: TestGCBugBareHashReferences (0.87s)930=== CONT TestIsValidUploadKey931=== RUN TestIsValidUploadKey/narinfo932=== PAUSE TestIsValidUploadKey/narinfo933=== RUN TestIsValidUploadKey/nar_zst934=== PAUSE TestIsValidUploadKey/nar_zst935=== RUN TestIsValidUploadKey/nar_xz936=== PAUSE TestIsValidUploadKey/nar_xz937=== RUN TestIsValidUploadKey/nar_plain938=== PAUSE TestIsValidUploadKey/nar_plain939=== RUN TestIsValidUploadKey/listing940=== PAUSE TestIsValidUploadKey/listing941=== RUN TestIsValidUploadKey/build_log942=== PAUSE TestIsValidUploadKey/build_log943=== RUN TestIsValidUploadKey/build_log_home-manager_file944=== PAUSE TestIsValidUploadKey/build_log_home-manager_file945=== RUN TestIsValidUploadKey/build_log_plus_in_name946=== PAUSE TestIsValidUploadKey/build_log_plus_in_name947=== RUN TestIsValidUploadKey/build_log_question_mark948=== PAUSE TestIsValidUploadKey/build_log_question_mark949=== RUN TestIsValidUploadKey/build_log_equals950=== PAUSE TestIsValidUploadKey/build_log_equals951=== RUN TestIsValidUploadKey/realisation952=== PAUSE TestIsValidUploadKey/realisation953=== RUN TestIsValidUploadKey/realisation_plus_in_output954=== PAUSE TestIsValidUploadKey/realisation_plus_in_output955=== RUN TestIsValidUploadKey/nix-cache-info956=== PAUSE TestIsValidUploadKey/nix-cache-info957=== RUN TestIsValidUploadKey/index.html958=== PAUSE TestIsValidUploadKey/index.html959=== RUN TestIsValidUploadKey/narinfo_key,_nar_type960=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type961=== RUN TestIsValidUploadKey/nar_key,_narinfo_type962=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type963=== RUN TestIsValidUploadKey/listing_key,_narinfo_type964=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type965=== RUN TestIsValidUploadKey/traversal966=== PAUSE TestIsValidUploadKey/traversal967=== RUN TestIsValidUploadKey/traversal_nar968=== PAUSE TestIsValidUploadKey/traversal_nar969=== RUN TestIsValidUploadKey/absolute970=== PAUSE TestIsValidUploadKey/absolute971=== RUN TestIsValidUploadKey/empty_key972=== PAUSE TestIsValidUploadKey/empty_key973=== RUN TestIsValidUploadKey/unknown_type974=== PAUSE TestIsValidUploadKey/unknown_type975=== CONT TestService_AuthMiddleware_MTLSBoundSubjects976=== NAME TestPinProtectsFromGC977 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2814019402/001/store/8cnp2qfyd4y06czq2m9vi7rcb4q6b97r-pinned-file.txt978 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2814019402/001/store/h1r51kcrlg811163iwfm1w36cnlxjd45-unpinned-file.txt979=== NAME TestClientMultipleUploads980 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4071165223/001/store/xp149hnn1p3a3irn7bsyz5ip15brqr18-test-file-0.txt981=== NAME TestClientIntegration982 client_integration_test.go:286: Created store path: /build/TestClientIntegration295260865/002/store/h85y54wfb742dvrm897v5y5br83bfjwg-test-file.txt983=== NAME TestClientMultipleUploads984 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4071165223/001/store/70fhbvx70nrdnw7w6dm45rmz3yw69nrk-test-file-1.txt985=== NAME TestClientWithDependencies986 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2555663308/001/store/skd2xn9c5grh3j8pqvvpqjc8sf1wxy6g-test-script987--- PASS: TestCacheStatsHandler (0.45s)988=== CONT TestService_AuthMiddleware_MTLSProxyHeader989--- PASS: TestService_ReadScope_PublicByDefault (0.45s)990=== CONT TestIsValidCachePath991=== RUN TestIsValidCachePath/narinfo992=== PAUSE TestIsValidCachePath/narinfo993=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars994=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars995=== RUN TestIsValidCachePath/nar_zst996=== PAUSE TestIsValidCachePath/nar_zst997=== RUN TestIsValidCachePath/nar_xz998=== PAUSE TestIsValidCachePath/nar_xz999=== RUN TestIsValidCachePath/nar_bz21000=== PAUSE TestIsValidCachePath/nar_bz21001=== RUN TestIsValidCachePath/nar_uncompressed1002=== PAUSE TestIsValidCachePath/nar_uncompressed1003=== RUN TestIsValidCachePath/ls1004=== PAUSE TestIsValidCachePath/ls1005=== RUN TestIsValidCachePath/log1006=== PAUSE TestIsValidCachePath/log1007=== RUN TestIsValidCachePath/realisation1008=== PAUSE TestIsValidCachePath/realisation1009=== RUN TestIsValidCachePath/nix-cache-info1010=== PAUSE TestIsValidCachePath/nix-cache-info1011=== RUN TestIsValidCachePath/index.html1012=== PAUSE TestIsValidCachePath/index.html1013=== RUN TestIsValidCachePath/traversal_parent1014=== PAUSE TestIsValidCachePath/traversal_parent1015=== RUN TestIsValidCachePath/traversal_in_middle1016=== PAUSE TestIsValidCachePath/traversal_in_middle1017=== RUN TestIsValidCachePath/invalid_char_e1018=== PAUSE TestIsValidCachePath/invalid_char_e1019=== RUN TestIsValidCachePath/invalid_char_u1020=== PAUSE TestIsValidCachePath/invalid_char_u1021=== RUN TestIsValidCachePath/random_path1022=== PAUSE TestIsValidCachePath/random_path1023=== RUN TestIsValidCachePath/empty1024=== PAUSE TestIsValidCachePath/empty1025=== RUN TestIsValidCachePath/leading_slash1026=== PAUSE TestIsValidCachePath/leading_slash10272026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures1028=== RUN TestIsValidCachePath/wrong_extension1029=== PAUSE TestIsValidCachePath/wrong_extension1030=== RUN TestIsValidCachePath/short_hash1031=== PAUSE TestIsValidCachePath/short_hash1032=== CONT TestMultipartCleanup10332026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes10342026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes10352026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/05 11:18:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10372026/10/05 11:18:44 INFO Uploading nfbc02mmp7kjcpwdnhdjjjr21x3f108k-shared-dep (136B)10382026/10/05 11:18:44 INFO Uploading v6kf53kiqwi6b0c5x36b0d290p389bcy-a (216B)10392026/10/05 11:18:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10402026/10/05 11:18:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10412026/10/05 11:18:44 INFO Uploading cwlnpdi7apa5pnbjc0cr6yadq2dkzfv5-shared-dep (136B)10422026/10/05 11:18:44 INFO Uploading cgjskgnfbqh6qzr1i1l5652xa96hr0w3-top (224B)10432026/10/05 11:18:44 INFO Uploading kgw1h47my5yvcblda18hd6xb4xx0m0pc-shared-dep (136B)10442026/10/05 11:18:44 INFO Uploading wpcd63x5phga1914iz30na6lmxwvhifj-a (216B)1045=== NAME TestClientWithDependencies1046 client_integration_test.go:615: Found 1 dependencies (including self)10472026/10/05 11:18:44 WARN Failed to register uploaded object key=s1cdpr8aapzc8k69a73p0cnjdnf4aghj.ls error="server returned 404: 404 page not found\n"10482026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10492026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/191l98sngsj6qfkd07p4lmrcpwkshb78nzfbzhmijf47fjbzyiq4.nar.zst error="server returned 404: 404 page not found\n"1050=== NAME TestClientMultipleUploads1051 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4071165223/001/store/c2k5zki1fsbv021bhad22gwj04jlqm67-test-file-2.txt10522026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10532026/10/05 11:18:44 WARN Failed to register uploaded object key=nfbc02mmp7kjcpwdnhdjjjr21x3f108k.ls error="server returned 404: 404 page not found\n"10542026/10/05 11:18:44 WARN Failed to register uploaded object key=cnnjzjdbibn7s0jzcyxbv0a8abz12dbz.ls error="server returned 404: 404 page not found\n"10552026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10562026/10/05 11:18:44 WARN Failed to register uploaded object key=v6kf53kiqwi6b0c5x36b0d290p389bcy.ls error="server returned 404: 404 page not found\n"10572026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/1x1w03dhiyn2iypgj9qkywd7aqf3yb1dj9bx7529ragp9vgi1yp6.nar.zst error="server returned 404: 404 page not found\n"10582026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10592026/10/05 11:18:44 WARN Failed to register uploaded object key=cwlnpdi7apa5pnbjc0cr6yadq2dkzfv5.ls error="server returned 404: 404 page not found\n"10602026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10612026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/14jljiidb4n3d4zb6dn3gpzww5zrhgkfw2i9d7pz6ifcbjchhd5d.nar.zst error="server returned 404: 404 page not found\n"10622026/10/05 11:18:44 WARN Failed to register uploaded object key=cgjskgnfbqh6qzr1i1l5652xa96hr0w3.ls error="server returned 404: 404 page not found\n"10632026/10/05 11:18:44 INFO Signed narinfos id=1 count=210642026/10/05 11:18:44 WARN Failed to register uploaded object key=kgw1h47my5yvcblda18hd6xb4xx0m0pc.ls error="server returned 404: 404 page not found\n"10652026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10662026/10/05 11:18:44 INFO Signed narinfos id=1 count=210672026/10/05 11:18:44 INFO Uploading 2 narinfos10682026/10/05 11:18:44 INFO Signed narinfos id=2 count=210692026/10/05 11:18:44 INFO Uploading 4 narinfos10702026/10/05 11:18:44 WARN Failed to register uploaded object key=wpcd63x5phga1914iz30na6lmxwvhifj.ls error="server returned 404: 404 page not found\n"10712026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10722026/10/05 11:18:44 INFO Signed narinfos id=1 count=310732026/10/05 11:18:44 INFO Uploading 3 narinfos10742026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes10752026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures10762026/10/05 11:18:44 WARN Failed to register uploaded object key=cgjskgnfbqh6qzr1i1l5652xa96hr0w3.narinfo error="server returned 404: 404 page not found\n"10772026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10782026/10/05 11:18:44 WARN Failed to register uploaded object key=nfbc02mmp7kjcpwdnhdjjjr21x3f108k.narinfo error="server returned 404: 404 page not found\n"10792026/10/05 11:18:44 WARN Failed to register uploaded object key=v6kf53kiqwi6b0c5x36b0d290p389bcy.narinfo error="server returned 404: 404 page not found\n"10802026/10/05 11:18:44 WARN Failed to register uploaded object key=cwlnpdi7apa5pnbjc0cr6yadq2dkzfv5.narinfo error="server returned 404: 404 page not found\n"10812026/10/05 11:18:44 WARN Failed to register uploaded object key=s1cdpr8aapzc8k69a73p0cnjdnf4aghj.narinfo error="server returned 404: 404 page not found\n"10822026/10/05 11:18:44 WARN Failed to register uploaded object key=kgw1h47my5yvcblda18hd6xb4xx0m0pc.narinfo error="server returned 404: 404 page not found\n"10832026/10/05 11:18:44 WARN Failed to register uploaded object key=cnnjzjdbibn7s0jzcyxbv0a8abz12dbz.narinfo error="server returned 404: 404 page not found\n"10842026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10852026/10/05 11:18:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10862026/10/05 11:18:44 WARN Failed to register uploaded object key=nfbc02mmp7kjcpwdnhdjjjr21x3f108k.narinfo error="server returned 404: 404 page not found\n"10872026/10/05 11:18:44 WARN Failed to register uploaded object key=wpcd63x5phga1914iz30na6lmxwvhifj.narinfo error="server returned 404: 404 page not found\n"10882026/10/05 11:18:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10892026/10/05 11:18:44 INFO Uploading 8cnp2qfyd4y06czq2m9vi7rcb4q6b97r-pinned-file.txt (128B)10902026/10/05 11:18:44 INFO Upload complete. (74ms)10912026/10/05 11:18:44 INFO Completed upload id=110922026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10932026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10942026/10/05 11:18:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10952026/10/05 11:18:44 WARN Failed to register uploaded object key=8cnp2qfyd4y06czq2m9vi7rcb4q6b97r.ls error="server returned 404: 404 page not found\n"10962026/10/05 11:18:44 INFO Signed narinfos id=1 count=11097=== NAME TestClientSharedPathCommittedMidPush1098 client_integration_test.go:680: Retrieved narinfo from S3:1099 StorePath: /build/TestClientSharedPathCommittedMidPush2602306292/001/store/cwlnpdi7apa5pnbjc0cr6yadq2dkzfv5-shared-dep1100 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1101 Compression: zstd1102 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821103 NarSize: 13611042026/10/05 11:18:44 INFO Upload complete. (77ms)1105 References: 1106 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11072026/10/05 11:18:44 INFO Uploading 1 narinfos11082026/10/05 11:18:44 INFO Completed upload id=211092026/10/05 11:18:44 INFO Upload complete. (83ms)1110=== NAME TestClientPushesUseOnePush1111 client_pushes_test.go:97: Retrieved narinfo from S3:1112 StorePath: /build/TestClientPushesUseOnePush1714756380/001/store/kgw1h47my5yvcblda18hd6xb4xx0m0pc-shared-dep1113 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1114 Compression: zstd1115 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821116 NarSize: 1361117 References: 1118 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1119--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.46s)1120=== CONT TestCompletedNarNotReofferedAcrossClosures11212026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes1122=== NAME TestClientFallsBackToClosures1123 client_pushes_test.go:112: Retrieved narinfo from S3:1124 StorePath: /build/TestClientFallsBackToClosures940598047/001/store/nfbc02mmp7kjcpwdnhdjjjr21x3f108k-shared-dep1125 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1126 Compression: zstd1127 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821128 NarSize: 1361129 References: 1130 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1131=== NAME TestClientSharedPathCommittedMidPush1132 client_integration_test.go:680: Retrieved narinfo from S3:1133 StorePath: /build/TestClientSharedPathCommittedMidPush2602306292/001/store/cgjskgnfbqh6qzr1i1l5652xa96hr0w3-top1134 URL: nar/1x1w03dhiyn2iypgj9qkywd7aqf3yb1dj9bx7529ragp9vgi1yp6.nar.zst1135 Compression: zstd1136 NarHash: sha256:1x1w03dhiyn2iypgj9qkywd7aqf3yb1dj9bx7529ragp9vgi1yp61137 NarSize: 2241138 References: /build/TestClientSharedPathCommittedMidPush2602306292/001/store/cwlnpdi7apa5pnbjc0cr6yadq2dkzfv5-shared-dep1139 CA: text:sha256:0ihl4akpy8z1p3vqnpwslixfl9j04h21ryig4573ddsz1lhhdm3p1140=== NAME TestClientPushesUseOnePush1141 client_pushes_test.go:97: Retrieved narinfo from S3:1142 StorePath: /build/TestClientPushesUseOnePush1714756380/001/store/wpcd63x5phga1914iz30na6lmxwvhifj-a1143 URL: nar/14jljiidb4n3d4zb6dn3gpzww5zrhgkfw2i9d7pz6ifcbjchhd5d.nar.zst11442026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete1145 Compression: zstd1146 NarHash: sha256:14jljiidb4n3d4zb6dn3gpzww5zrhgkfw2i9d7pz6ifcbjchhd5d1147 NarSize: 2161148 References: /build/TestClientPushesUseOnePush1714756380/001/store/kgw1h47my5yvcblda18hd6xb4xx0m0pc-shared-dep11492026/10/05 11:18:44 WARN Failed to register uploaded object key=8cnp2qfyd4y06czq2m9vi7rcb4q6b97r.narinfo error="server returned 404: 404 page not found\n"1150 CA: text:sha256:013rrbi64pag5jxjlbk2dyr7xmsr76laaqsp4j3lcsqlgm542kyc1151=== NAME TestClientFallsBackToClosures1152 client_pushes_test.go:112: Retrieved narinfo from S3:1153 StorePath: /build/TestClientFallsBackToClosures940598047/001/store/v6kf53kiqwi6b0c5x36b0d290p389bcy-a1154 URL: nar/191l98sngsj6qfkd07p4lmrcpwkshb78nzfbzhmijf47fjbzyiq4.nar.zst1155 Compression: zstd1156 NarHash: sha256:191l98sngsj6qfkd07p4lmrcpwkshb78nzfbzhmijf47fjbzyiq41157 NarSize: 2161158 References: /build/TestClientFallsBackToClosures940598047/001/store/nfbc02mmp7kjcpwdnhdjjjr21x3f108k-shared-dep1159 CA: text:sha256:1z609v9z7cs7fd4p48ic5565nd0pv1gvc4zinhq4gwdxx0i56sa51160--- PASS: TestClientSharedPathCommittedMidPush (0.65s)1161=== CONT TestProxyHeadersOnlyTrustedOnSocket1162=== NAME TestClientPushesUseOnePush11632026/10/05 11:18:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1164 client_pushes_test.go:97: Retrieved narinfo from S3:11652026/10/05 11:18:44 INFO Uploading h85y54wfb742dvrm897v5y5br83bfjwg-test-file.txt (152B)1166 StorePath: /build/TestClientPushesUseOnePush1714756380/001/store/cnnjzjdbibn7s0jzcyxbv0a8abz12dbz-b1167 URL: nar/14jljiidb4n3d4zb6dn3gpzww5zrhgkfw2i9d7pz6ifcbjchhd5d.nar.zst1168 Compression: zstd1169 NarHash: sha256:14jljiidb4n3d4zb6dn3gpzww5zrhgkfw2i9d7pz6ifcbjchhd5d1170 NarSize: 2161171 References: /build/TestClientPushesUseOnePush1714756380/001/store/kgw1h47my5yvcblda18hd6xb4xx0m0pc-shared-dep1172 CA: text:sha256:013rrbi64pag5jxjlbk2dyr7xmsr76laaqsp4j3lcsqlgm542kyc11732026/10/05 11:18:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1174=== NAME TestClientFallsBackToClosures1175 client_pushes_test.go:112: Retrieved narinfo from S3:1176 StorePath: /build/TestClientFallsBackToClosures940598047/001/store/s1cdpr8aapzc8k69a73p0cnjdnf4aghj-b1177 URL: nar/191l98sngsj6qfkd07p4lmrcpwkshb78nzfbzhmijf47fjbzyiq4.nar.zst1178 Compression: zstd1179 NarHash: sha256:191l98sngsj6qfkd07p4lmrcpwkshb78nzfbzhmijf47fjbzyiq41180 NarSize: 2161181 References: /build/TestClientFallsBackToClosures940598047/001/store/nfbc02mmp7kjcpwdnhdjjjr21x3f108k-shared-dep1182 CA: text:sha256:1z609v9z7cs7fd4p48ic5565nd0pv1gvc4zinhq4gwdxx0i56sa511832026/10/05 11:18:44 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1184--- PASS: TestCompleteMultipartUnregistered (0.42s)1185=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11862026/10/05 11:18:44 INFO Upload complete. (72ms)1187--- PASS: TestClientFallsBackToClosures (0.75s)1188=== CONT TestParseSingleRange1189=== RUN TestParseSingleRange/none1190=== PAUSE TestParseSingleRange/none1191=== RUN TestParseSingleRange/unknown_unit1192=== PAUSE TestParseSingleRange/unknown_unit1193=== RUN TestParseSingleRange/multi-range_ignored1194=== PAUSE TestParseSingleRange/multi-range_ignored1195=== RUN TestParseSingleRange/malformed_no_dash1196=== PAUSE TestParseSingleRange/malformed_no_dash1197=== RUN TestParseSingleRange/malformed_both_empty1198=== PAUSE TestParseSingleRange/malformed_both_empty1199=== RUN TestParseSingleRange/malformed_end_before_start1200=== PAUSE TestParseSingleRange/malformed_end_before_start1201=== RUN TestParseSingleRange/closed1202=== PAUSE TestParseSingleRange/closed1203=== RUN TestParseSingleRange/open-ended1204=== PAUSE TestParseSingleRange/open-ended1205--- PASS: TestClientPushesUseOnePush (0.74s)1206=== CONT TestRedundantMultipartUpload1207=== RUN TestParseSingleRange/end_clamped_to_size12082026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1209=== PAUSE TestParseSingleRange/end_clamped_to_size1210=== RUN TestParseSingleRange/suffix1211=== PAUSE TestParseSingleRange/suffix1212=== RUN TestParseSingleRange/suffix_exceeds_size1213=== PAUSE TestParseSingleRange/suffix_exceeds_size12142026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1215=== RUN TestParseSingleRange/single_byte12162026/10/05 11:18:44 WARN Failed to register uploaded object key=h85y54wfb742dvrm897v5y5br83bfjwg.ls error="server returned 404: 404 page not found\n"1217=== PAUSE TestParseSingleRange/single_byte1218=== RUN TestParseSingleRange/start_past_EOF1219=== PAUSE TestParseSingleRange/start_past_EOF1220=== RUN TestParseSingleRange/start_far_past_EOF1221=== PAUSE TestParseSingleRange/start_far_past_EOF1222=== CONT TestPresentNotReportedWhileGCDeletesClosure12232026/10/05 11:18:44 INFO Signed narinfos id=1 count=112242026/10/05 11:18:44 INFO Uploading 1 narinfos12252026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12262026/10/05 11:18:44 WARN Failed to register uploaded object key=h85y54wfb742dvrm897v5y5br83bfjwg.narinfo error="server returned 404: 404 page not found\n"1227=== NAME TestClientCADerivations1228 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations450258634/001/store/39x6ajbm226qj8q89g88djaiji2rah1v-ca-test12292026/10/05 11:18:44 INFO Upload complete. (64ms)12302026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures12312026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures12322026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures12332026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes12342026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes12352026/10/05 11:18:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12362026/10/05 11:18:44 INFO Uploading skd2xn9c5grh3j8pqvvpqjc8sf1wxy6g-test-script (136B)1237 client_ca_test.go:139: Found 1 dependencies (including self)12382026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12392026/10/05 11:18:44 WARN Failed to register uploaded object key=skd2xn9c5grh3j8pqvvpqjc8sf1wxy6g.ls error="server returned 404: 404 page not found\n"12402026/10/05 11:18:44 WARN Failed to register uploaded object key=log/ahdvzkgzpgkx5ssm13x7c4x21k8ndlcb-test-script.drv error="server returned 404: 404 page not found\n"12412026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12422026/10/05 11:18:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12432026/10/05 11:18:44 INFO Uploading 70fhbvx70nrdnw7w6dm45rmz3yw69nrk-test-file-1.txt (160B)12442026/10/05 11:18:44 INFO Uploading xp149hnn1p3a3irn7bsyz5ip15brqr18-test-file-0.txt (160B)12452026/10/05 11:18:44 INFO Uploading c2k5zki1fsbv021bhad22gwj04jlqm67-test-file-2.txt (160B)12462026/10/05 11:18:44 INFO Signed narinfos id=1 count=112472026/10/05 11:18:44 INFO Uploading 1 narinfos12482026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures12492026/10/05 11:18:44 WARN Failed to register uploaded object key=70fhbvx70nrdnw7w6dm45rmz3yw69nrk.ls error="server returned 404: 404 page not found\n"12502026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12512026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12522026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12532026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12542026/10/05 11:18:44 WARN Failed to register uploaded object key=skd2xn9c5grh3j8pqvvpqjc8sf1wxy6g.narinfo error="server returned 404: 404 page not found\n"12552026/10/05 11:18:44 WARN Failed to register uploaded object key=xp149hnn1p3a3irn7bsyz5ip15brqr18.ls error="server returned 404: 404 page not found\n"12562026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12572026/10/05 11:18:44 WARN Failed to register uploaded object key=c2k5zki1fsbv021bhad22gwj04jlqm67.ls error="server returned 404: 404 page not found\n"12582026/10/05 11:18:44 INFO Signed narinfos id=1 count=312592026/10/05 11:18:44 INFO Uploading 3 narinfos12602026/10/05 11:18:44 INFO All 1 paths already cached1261=== NAME TestClientIntegration1262 client_integration_test.go:312: Retrieved narinfo from S3:1263 StorePath: /build/TestClientIntegration295260865/002/store/h85y54wfb742dvrm897v5y5br83bfjwg-test-file.txt1264 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1265 Compression: zstd1266 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11267 NarSize: 1521268 References: 1269 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk112702026/10/05 11:18:44 WARN Failed to register uploaded object key=xp149hnn1p3a3irn7bsyz5ip15brqr18.narinfo error="server returned 404: 404 page not found\n"12712026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12722026/10/05 11:18:44 WARN Failed to register uploaded object key=c2k5zki1fsbv021bhad22gwj04jlqm67.narinfo error="server returned 404: 404 page not found\n"12732026/10/05 11:18:44 WARN Failed to register uploaded object key=70fhbvx70nrdnw7w6dm45rmz3yw69nrk.narinfo error="server returned 404: 404 page not found\n"1274 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1275 client_integration_test.go:313: Decompressed .ls content (64 bytes):1276 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1277 client_integration_test.go:316: Testing garbage collection...12782026/10/05 11:18:44 INFO Upload complete. (80ms)12792026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes1280=== NAME TestClientWithDependencies1281 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2555663308/001/store) requires matching store prefix1282--- PASS: TestClientWithDependencies (0.70s)1283=== CONT TestPush_SignsNarinfosOfItsPendingObjects12842026/10/05 11:18:44 INFO Upload complete. (107ms)1285=== NAME TestClientMultipleUploads1286 client_integration_test.go:369: Uploaded 3 paths in 138.869735ms12872026/10/05 11:18:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12882026/10/05 11:18:44 INFO Uploading h1r51kcrlg811163iwfm1w36cnlxjd45-unpinned-file.txt (128B)12892026/10/05 11:18:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures12902026/10/05 11:18:44 INFO Garbage collection started12912026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12922026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12932026/10/05 11:18:44 WARN Failed to register uploaded object key=h1r51kcrlg811163iwfm1w36cnlxjd45.ls error="server returned 404: 404 page not found\n"12942026/10/05 11:18:44 INFO Signed narinfos id=2 count=112952026/10/05 11:18:44 INFO Uploading 1 narinfos1296--- PASS: TestClientMultipleUploads (0.71s)1297=== CONT TestPresentReportsOnlyClosureRoots12982026/10/05 11:18:44 INFO Aborted multipart uploads count=0 kept=012992026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/2/complete13002026/10/05 11:18:44 WARN Failed to register uploaded object key=h1r51kcrlg811163iwfm1w36cnlxjd45.narinfo error="server returned 404: 404 page not found\n"13012026/10/05 11:18:44 WARN Force mode enabled - objects will be deleted immediately without grace period13022026/10/05 11:18:44 INFO Upload complete. (88ms)1303=== RUN TestService_RequireScope_OIDC/builder_may_write1304=== PAUSE TestService_RequireScope_OIDC/builder_may_write1305=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1306=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1307=== RUN TestService_RequireScope_OIDC/ops_may_admin1308=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1309=== RUN TestService_RequireScope_OIDC/ops_may_not_write1310=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1311=== RUN TestService_RequireScope_OIDC/reader_may_not_write1312=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1313=== RUN TestService_RequireScope_OIDC/static_token_may_admin1314=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1315=== RUN TestService_RequireScope_OIDC/static_token_may_write1316=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1317=== RUN TestService_RequireScope_OIDC/reader_may_read1318=== PAUSE TestService_RequireScope_OIDC/reader_may_read1319=== RUN TestService_RequireScope_OIDC/writer_implies_read1320=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1321=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1322=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1323=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1324=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1325=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1326=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1327=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1328=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1329=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1330=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1331=== CONT TestPush_RejectsBadRequests13322026/10/05 11:18: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=013332026/10/05 11:18:44 INFO Vacuumed table table=pending_closures1334=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1335=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1336=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1337=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1338=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1339=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1340=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1341=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1342=== CONT TestCreatePin_ReservedPins13432026/10/05 11:18:44 INFO Vacuumed table table=pending_objects13442026/10/05 11:18:44 INFO Vacuumed table table=multipart_uploads13452026/10/05 11:18:44 INFO Vacuumed table table=closures13462026/10/05 11:18:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures13472026/10/05 11:18:44 INFO Garbage collection started13482026/10/05 11:18:44 INFO Vacuumed table table=objects1349--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.94s)1350=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit13512026/10/05 11:18:44 INFO Aborted multipart uploads count=0 kept=013522026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes13532026/10/05 11:18:44 WARN Force mode enabled - objects will be deleted immediately without grace period1354--- PASS: TestService_ReadAuthMiddleware (0.39s)1355=== CONT TestUploadHandlersRejectOversizedBody1356--- PASS: TestPushWaitsForSweepHoldingRow (1.27s)1357=== CONT TestPush_CompleteCommitsEveryRoot13582026/10/05 11:18:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13592026/10/05 11:18:44 INFO Uploading 39x6ajbm226qj8q89g88djaiji2rah1v-ca-test (144B)13602026/10/05 11:18:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13612026/10/05 11:18:44 WARN mTLS auth: bound subjects configured but subject DN unavailable13622026/10/05 11:18:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1363--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.45s)1364=== CONT TestOrphanedObjectsGCStressTest13652026/10/05 11:18:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43645/oidc13662026/10/05 11:18:44 WARN Failed to register uploaded object key=39x6ajbm226qj8q89g88djaiji2rah1v.ls error="server returned 404: 404 page not found\n"13672026/10/05 11:18:44 WARN Failed to register uploaded object key=log/vfznxszkxg3lciihlr2h07whxizplir0-ca-test.drv error="server returned 404: 404 page not found\n"13682026/10/05 11:18:44 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13692026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13702026/10/05 11:18:44 INFO Signed narinfos id=1 count=113712026/10/05 11:18:44 INFO Uploading 1 narinfos13722026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete13732026/10/05 11:18:44 WARN Failed to register uploaded object key=39x6ajbm226qj8q89g88djaiji2rah1v.narinfo error="server returned 404: 404 page not found\n"13742026/10/05 11:18: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=013752026/10/05 11:18:44 INFO Upload complete. (183ms)13762026/10/05 11:18:44 INFO Vacuumed table table=pending_closures1377=== NAME TestClientCADerivations1378 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations450258634/001/store/39x6ajbm226qj8q89g88djaiji2rah1v-ca-test1379 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1380 Compression: zstd1381 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1382 NarSize: 1441383 References: 13842026/10/05 11:18:44 INFO Vacuumed table table=pending_objects1385 Deriver: /build/TestClientCADerivations450258634/001/store/vfznxszkxg3lciihlr2h07whxizplir0-ca-test.drv1386 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1387 client_ca_test.go:185: Checking for realisation files in S3...13882026/10/05 11:18:44 INFO Vacuumed table table=multipart_uploads1389 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1390 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13912026/10/05 11:18:44 INFO Vacuumed table table=closures1392--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)1393=== CONT TestService_cleanupPendingClosuresHandler13942026/10/05 11:18:44 INFO Vacuumed table table=objects13952026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures13962026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures1397=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1398=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1399=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1400=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1401=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1402=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1403=== CONT TestPush_OverlappingRootsStoreOneRowPerKey14042026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures1405=== NAME TestClientCADerivations1406 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1407 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1408 error: binary cache 's3://bucket34?endpoint=http://localhost:36301®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations450258634/001/store'1409 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11410--- PASS: TestClientCADerivations (0.92s)1411=== CONT TestOrphanedObjectsGC14122026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures14132026/10/05 11:18:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14142026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures14152026/10/05 11:18: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=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LjJjMjVmOTM5LWU5MzAtNGQxYS04ODUwLTIxMzg1ZjMzZDdkNngxNzkxMTk5MTI0NzE5MDc0OTM114162026/10/05 11:18:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LjJjMjVmOTM5LWU5MzAtNGQxYS04ODUwLTIxMzg1ZjMzZDdkNngxNzkxMTk5MTI0NzE5MDc0OTM1 parts=11417--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.42s)1418=== CONT TestReadRedirectUsesPublicS3URL14192026/10/05 11:18:44 INFO Received cleanup request method=DELETE path=/api/pending_closures14202026/10/05 11:18:44 INFO Starting HTTP server address=127.0.0.1:4242314212026/10/05 11:18:44 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3616164586/001/proxy.sock14222026/10/05 11:18:44 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14232026/10/05 11:18:44 INFO Shutdown signal received, draining in-flight requests timeout=10s14242026/10/05 11:18:44 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14252026/10/05 11:18:44 INFO Aborted multipart uploads count=0 kept=11426--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.43s)1427=== CONT TestPendingCleanupUsesOneCutoff14282026/10/05 11:18:44 INFO Received cleanup request method=DELETE path=/api/pending_closures14292026/10/05 11:18:44 INFO Aborted multipart uploads count=1 kept=014302026/10/05 11:18:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1431--- PASS: TestMultipartCleanup (0.50s)1432=== CONT TestReadProxyRangeRequest14332026/10/05 11:18:44 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LmQxYTk2ZDdjLTdlZTktNDY0Ni1hYjJmLTc1ZmUzOGFkZTk3NngxNzkxMTk5MTI0Mzg1MTgyOTY1 parts=1014342026/10/05 11:18:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14352026/10/05 11:18:44 INFO Completed upload id=114362026/10/05 11:18:44 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014372026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures14382026/10/05 11:18:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures14392026/10/05 11:18:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14402026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes14412026/10/05 11:18:44 INFO Aborted multipart uploads count=0 kept=014422026/10/05 11:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14432026/10/05 11:18:44 INFO Signed narinfos id=1 count=11444--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.40s)1445=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14462026/10/05 11:18:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014472026/10/05 11:18:44 INFO Vacuumed table table=pending_closures14482026/10/05 11:18:44 INFO Vacuumed table table=pending_objects14492026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes14502026/10/05 11:18:44 INFO Vacuumed table table=multipart_uploads14512026/10/05 11:18:44 INFO Vacuumed table table=closures14522026/10/05 11:18:44 INFO Vacuumed table table=objects14532026/10/05 11:18:44 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014542026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete1455--- PASS: TestService_createPendingClosureHandler (0.91s)1456=== CONT TestObjectStatsTrigger1457=== RUN TestPush_RejectsBadRequests/no_objects1458=== PAUSE TestPush_RejectsBadRequests/no_objects1459=== RUN TestPush_RejectsBadRequests/bad_root1460=== PAUSE TestPush_RejectsBadRequests/bad_root1461=== RUN TestPush_RejectsBadRequests/root_not_in_objects1462=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1463=== RUN TestPush_RejectsBadRequests/no_roots1464=== PAUSE TestPush_RejectsBadRequests/no_roots1465=== CONT TestReadRedirectKeepsNarinfoProxied14662026/10/05 11:18:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LmIzZDgyNWM3LWQ1ZWMtNDM3Ny05YTRkLWVhZGUyMzFlNzIxZXgxNzkxMTk5MTI0NDI2MTM4MzY5 parts=1014672026/10/05 11:18:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14682026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes14692026/10/05 11:18:44 INFO Completed upload id=114702026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures14712026/10/05 11:18:44 INFO Received uploads request method=POST path=/api/pending_closures14722026/10/05 11:18:44 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14732026/10/05 11:18:44 WARN Found objects in DB but missing from S3, will re-upload count=11474--- PASS: TestService_verifyS3Integrity (0.94s)1475=== CONT TestReadRedirectNar1476--- PASS: TestPresentReportsOnlyClosureRoots (0.45s)1477=== CONT TestCacheConfigHandlerMaxNarSize1478--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1479=== CONT TestReadProxyDisabled14802026/10/05 11:18:44 INFO Received push request method=POST path=/api/pushes14812026/10/05 11:18:44 INFO Aborted multipart uploads count=0 kept=014822026/10/05 11:18:44 WARN Force mode enabled - objects will be deleted immediately without grace period14832026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14842026/10/05 11:18: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=014852026/10/05 11:18:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14862026/10/05 11:18:44 WARN Refused reserved pin name=worker-x86_64-linux14872026/10/05 11:18:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14882026/10/05 11:18:44 INFO Received create pin request method=POST path=/api/pins/my-app14892026/10/05 11:18:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1490--- PASS: TestPush_CompleteCommitsEveryRoot (0.43s)1491=== CONT TestServerTLSConfig1492=== RUN TestServerTLSConfig/no_client_CA14932026/10/05 11:18:44 INFO Vacuumed table table=pending_closures1494=== PAUSE TestServerTLSConfig/no_client_CA1495=== RUN TestServerTLSConfig/missing_CA_file1496=== PAUSE TestServerTLSConfig/missing_CA_file1497=== RUN TestServerTLSConfig/not_a_PEM_file1498=== PAUSE TestServerTLSConfig/not_a_PEM_file1499=== CONT TestService_NativeMTLS1500--- PASS: TestCreatePin_ReservedPins (0.46s)1501=== CONT TestService_healthCheckHandler15022026/10/05 11:18:44 INFO Vacuumed table table=pending_objects15032026/10/05 11:18:44 INFO Vacuumed table table=multipart_uploads15042026/10/05 11:18:44 INFO Vacuumed table table=closures15052026/10/05 11:18:44 INFO Vacuumed table table=objects15062026/10/05 11:18:44 INFO Received complete push request method=POST path=/api/pushes/2/complete1507--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.47s)1508=== CONT TestReadProxyRootRedirectsToIndexHTML15092026/10/05 11:18:44 INFO lead: released remote=192.0.2.1:12341510--- PASS: TestLeadEndsOnShutdown (1.72s)1511=== CONT TestMetricsInventory15122026/10/05 11:18:45 INFO Received cleanup request method=DELETE path=/api/pending_closures15132026/10/05 11:18:45 INFO Aborted multipart uploads count=0 kept=015142026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures15152026/10/05 11:18:45 INFO Received cleanup request method=DELETE path=/api/pending_closures15162026/10/05 11:18:45 INFO Aborted multipart uploads count=1 kept=015172026/10/05 11:18:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15182026/10/05 11:18:45 INFO Received push request method=POST path=/api/pushes15192026-10-05 11:18:45.059 UTC [1370] ERROR: Closure does not exist: id=115202026-10-05 11:18:45.059 UTC [1370] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE15212026-10-05 11:18:45.059 UTC [1370] STATEMENT: -- name: CommitPendingClosure :exec1522 SELECT commit_pending_closure($1::bigint)1523 1524--- PASS: TestService_cleanupPendingClosuresHandler (0.44s)1525=== CONT TestGenerateLandingPage1526--- PASS: TestGenerateLandingPage (0.00s)1527=== CONT TestReadProxyConditionalGet1528--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.40s)1529=== CONT TestService_readinessHandler15302026/10/05 11:18:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15312026/10/05 11:18:45 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LjUyNDJiN2IzLWFjNGMtNDMwMy04YjNjLTgxYWE3ZTQ0NmM3MngxNzkxMTk5MTI0Njg4NTI2MDAz parts=1215322026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures15332026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures1534--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.78s)1535=== CONT TestReadProxyOutlastsServerWriteTimeout15362026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures15372026/10/05 11:18:45 INFO Received cleanup request method=DELETE path=/api/pending_closures15382026/10/05 11:18:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1539--- PASS: TestReadRedirectUsesPublicS3URL (0.38s)1540=== CONT TestNARDeduplicationMetadataUploadBug15412026/10/05 11:18:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LjMyNmQ5MGVjLWNjZWEtNDI2ZS05N2ZkLTYzMjU5ODY3ODRlN3gxNzkxMTk5MTI0NzUxMDM3NTE5 parts=121542--- PASS: TestReadProxyRangeRequest (0.38s)1543=== CONT TestReadProxyHead15442026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures15452026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures15462026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures1547--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.37s)1548=== CONT TestReadProxyNarStreaming1549--- PASS: TestReadRedirectKeepsNarinfoProxied (0.36s)1550=== CONT TestCreatePendingClosureRejectsOversizedNAR15512026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures1552--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1553=== CONT TestReadProxyInvalidPath1554--- PASS: TestObjectStatsTrigger (0.40s)1555=== CONT TestReadProxyNarinfoAlreadyDecompressed1556--- PASS: TestReadRedirectNar (0.38s)1557=== CONT TestGracefulShutdownDrainsInflight15582026/10/05 11:18:45 INFO Starting HTTP server address=127.0.0.1:3323515592026/10/05 11:18:45 INFO Shutdown signal received, draining in-flight requests timeout=10s1560--- PASS: TestReadProxyDisabled (0.37s)1561=== CONT TestReadProxy40415622026/10/05 11:18:45 INFO lead: released remote=192.0.2.1:12341563--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.95s)1564=== CONT TestReadProxyNarinfo15652026/10/05 11:18:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15662026/10/05 11:18:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1567--- PASS: TestService_NativeMTLS (0.34s)1568=== CONT TestGCTaskStore_Fail1569--- PASS: TestGCTaskStore_Fail (0.00s)1570=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1571--- PASS: TestService_healthCheckHandler (0.37s)1572=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1573--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1574=== CONT TestProxyWriteTimeout/narinfo1575=== CONT TestProxyWriteTimeout/1_GiB_nar1576=== CONT TestProxyWriteTimeout/unknown_size1577=== CONT TestProxyWriteTimeout/10_GiB_nar1578--- PASS: TestProxyWriteTimeout (0.01s)1579 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1580 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1581 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1582 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1583=== CONT TestPendingClosureWriteTimeout/empty1584=== CONT TestPendingClosureWriteTimeout/670k_objects1585=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15862026/10/05 11:18:45 INFO lead: acquired remote=192.0.2.1:12341587--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.38s)1588=== CONT TestPendingClosureWriteTimeout/400_objects1589=== CONT TestGCEndsOnShutdown/before_the_run1590--- PASS: TestMetricsInventory (0.42s)1591=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1592--- PASS: TestReadProxyConditionalGet (0.36s)1593=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1594=== NAME TestOrphanedObjectsGC1595 orphaned_objects_gc_test.go:290: GC Test Summary:1596 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1597 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1598 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1599 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1600 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1601--- PASS: TestOrphanedObjectsGC (0.69s)1602=== CONT TestResolveDBConnectionString/flag_wins1603=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1604=== CONT TestResolveDBConnectionString/nothing_configured1605=== CONT TestResolveDBConnectionString/missing_file_is_an_error1606=== CONT TestResolveDBConnectionString/file_when_flag_empty1607=== CONT TestClientErrorHandling/InvalidStorePath1608--- PASS: TestResolveDBConnectionString (0.00s)1609 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1610 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1611 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1612 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1613 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16142026/10/05 11:18:45 WARN readiness check failed error="closed pool"1615--- PASS: TestService_readinessHandler (0.36s)1616=== CONT TestClientErrorHandling/ServerNotAvailable16172026/10/05 11:18:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1618--- PASS: TestReadProxyHead (0.35s)1619=== CONT TestClientErrorHandling/InvalidAuthToken1620=== NAME TestNARDeduplicationMetadataUploadBug1621 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug592579886/001/store/1ff25m39g9g4lrwvb84swq70hw737435-file1.txt1622--- PASS: TestReadProxyNarStreaming (0.34s)1623=== CONT TestCacheConfigHandler/full_config,_no_issuer1624=== CONT TestCacheConfigHandler/no_signing_keys1625=== CONT TestCacheConfigHandler/no_cache_url_configured1626=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1627--- PASS: TestCacheConfigHandler (0.00s)1628 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1629 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1630 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1631 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1632=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16332026/10/05 11:18:45 INFO Received uploads request method=POST path=/1634=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16352026/10/05 11:18:45 INFO Received request for more parts method=POST path=/1636=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16372026/10/05 11:18:45 INFO Received complete multipart upload request method=POST path=/1638=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16392026/10/05 11:18:45 INFO Received uploads request method=POST path=/1640--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1641 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1642 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1643 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1644 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1645=== CONT TestIsValidUploadKey/narinfo1646=== CONT TestIsValidUploadKey/unknown_type1647=== CONT TestIsValidUploadKey/empty_key1648=== CONT TestIsValidUploadKey/absolute1649=== CONT TestIsValidUploadKey/traversal_nar1650=== CONT TestIsValidUploadKey/traversal1651=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1652=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1653=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1654=== CONT TestIsValidUploadKey/index.html1655=== CONT TestIsValidUploadKey/nix-cache-info1656=== CONT TestIsValidUploadKey/realisation_plus_in_output1657=== CONT TestIsValidUploadKey/realisation1658=== CONT TestIsValidUploadKey/build_log_equals1659=== CONT TestIsValidUploadKey/build_log_question_mark1660=== CONT TestIsValidUploadKey/build_log_plus_in_name1661=== CONT TestIsValidUploadKey/build_log_home-manager_file1662=== CONT TestIsValidUploadKey/build_log1663=== CONT TestIsValidUploadKey/listing1664=== CONT TestIsValidUploadKey/nar_plain1665=== CONT TestIsValidUploadKey/nar_xz1666=== CONT TestIsValidUploadKey/nar_zst1667=== CONT TestIsValidCachePath/narinfo1668=== CONT TestIsValidCachePath/index.html1669=== CONT TestIsValidCachePath/short_hash1670=== CONT TestIsValidCachePath/wrong_extension1671=== CONT TestIsValidCachePath/nar_uncompressed1672=== CONT TestIsValidCachePath/leading_slash1673=== CONT TestIsValidCachePath/nix-cache-info1674=== CONT TestIsValidCachePath/empty1675--- PASS: TestIsValidUploadKey (0.00s)1676 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1677 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1678 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1679 --- PASS: TestIsValidUploadKey/absolute (0.00s)1680 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1681 --- PASS: TestIsValidUploadKey/traversal (0.00s)1682 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1683 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1684 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1685 --- PASS: TestIsValidUploadKey/index.html (0.00s)1686 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1687 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1688 --- PASS: TestIsValidUploadKey/realisation (0.00s)1689 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1690 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1691 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1692 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1693 --- PASS: TestIsValidUploadKey/build_log (0.00s)1694 --- PASS: TestIsValidUploadKey/listing (0.00s)1695 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1696 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1697 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1698=== CONT TestIsValidCachePath/realisation1699=== CONT TestIsValidCachePath/random_path1700=== CONT TestIsValidCachePath/log1701=== CONT TestIsValidCachePath/invalid_char_u1702=== CONT TestIsValidCachePath/invalid_char_e1703=== CONT TestIsValidCachePath/nar_xz1704=== CONT TestIsValidCachePath/traversal_in_middle1705=== CONT TestIsValidCachePath/nar_bz21706=== CONT TestIsValidCachePath/traversal_parent1707=== CONT TestIsValidCachePath/ls1708=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1709=== CONT TestIsValidCachePath/nar_zst1710--- PASS: TestIsValidCachePath (0.00s)1711 --- PASS: TestIsValidCachePath/narinfo (0.00s)1712 --- PASS: TestIsValidCachePath/index.html (0.00s)1713 --- PASS: TestIsValidCachePath/short_hash (0.00s)1714 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1715 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1716 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1717 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1718 --- PASS: TestIsValidCachePath/empty (0.00s)1719 --- PASS: TestIsValidCachePath/realisation (0.00s)1720 --- PASS: TestIsValidCachePath/random_path (0.00s)1721 --- PASS: TestIsValidCachePath/log (0.00s)1722 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1723 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1724 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1725 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1726 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1727 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1728 --- PASS: TestIsValidCachePath/ls (0.00s)1729 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1730 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1731=== CONT TestParseSingleRange/none1732=== CONT TestParseSingleRange/end_clamped_to_size1733=== CONT TestParseSingleRange/start_far_past_EOF1734=== CONT TestParseSingleRange/start_past_EOF1735=== CONT TestParseSingleRange/single_byte1736=== CONT TestParseSingleRange/suffix_exceeds_size1737=== CONT TestParseSingleRange/open-ended1738=== CONT TestParseSingleRange/suffix1739=== CONT TestParseSingleRange/malformed_both_empty1740=== CONT TestParseSingleRange/malformed_end_before_start1741=== CONT TestParseSingleRange/multi-range_ignored1742=== CONT TestParseSingleRange/unknown_unit1743=== CONT TestParseSingleRange/closed1744=== CONT TestParseSingleRange/malformed_no_dash1745--- PASS: TestParseSingleRange (0.00s)1746 --- PASS: TestParseSingleRange/none (0.00s)1747 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1748 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1749 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1750 --- PASS: TestParseSingleRange/single_byte (0.00s)1751 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1752 --- PASS: TestParseSingleRange/open-ended (0.00s)1753 --- PASS: TestParseSingleRange/suffix (0.00s)1754 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1755 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1756 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1757 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1758 --- PASS: TestParseSingleRange/closed (0.00s)1759 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1760=== CONT TestService_RequireScope_OIDC/builder_may_write1761=== CONT TestService_RequireScope_OIDC/reader_may_read1762=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1763=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17642026/10/05 11:18:45 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1765=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1766=== CONT TestService_RequireScope_OIDC/writer_implies_read1767=== CONT TestService_RequireScope_OIDC/reader_may_not_write1768=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1769=== CONT TestService_RequireScope_OIDC/static_token_may_write1770=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1771=== CONT TestService_RequireScope_OIDC/static_token_may_admin1772=== CONT TestService_RequireScope_OIDC/ops_may_admin1773=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1774=== CONT TestService_RequireScope_OIDC/ops_may_not_write1775=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1776--- PASS: TestService_RequireScope_OIDC (0.62s)1777 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1778 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1779 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1780 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1781 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1782 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1783 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1784 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1785 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1786 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1787 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1788 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1789 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1790 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1791=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17922026/10/05 11:18:45 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1793=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1794=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17952026/10/05 11:18:45 WARN Authentication failed token_preview=eyJhbGciOi...hmKptXuOzQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1796=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17972026/10/05 11:18:45 INFO Received uploads request method=POST path=/1798--- PASS: TestService_AuthMiddleware_OIDC (0.52s)1799 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1800 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1801 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1802 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1803--- PASS: TestReadProxyInvalidPath (0.33s)1804=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18052026/10/05 11:18:45 INFO Received request for more parts method=POST path=/18062026/10/05 11:18:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18072026/10/05 11:18:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LjU0Y2NhZDk1LTllZjItNGE3NC04OTZlLTliMGRlYmU4ZWM2N3gxNzkxMTk5MTI1MTgzMTkwMDIy error="Get \"http://127.0.0.1:1/bucket49/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18082026/10/05 11:18:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmQxZTQ4OTktNzM5OS00MDhjLThjOGEtZGM3MDA5YjI4ZWU5LmM2MzU0MWZiLWY4YmItNDNhYy05ZTQ0LWE4MjNlMjljMWFjYXgxNzkxMTk5MTI1MTc2MTE5Mzk5 parts=1218092026/10/05 11:18:45 INFO Received cleanup request method=DELETE path=/api/pending_closures1810--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.33s)1811=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18122026/10/05 11:18:45 INFO Received complete multipart upload request method=POST path=/18132026/10/05 11:18:45 INFO Aborted multipart uploads count=1 kept=01814--- PASS: TestRedundantMultipartUpload (1.25s)1815=== CONT TestPush_RejectsBadRequests/no_objects18162026/10/05 11:18:45 INFO Received push request method=POST path=/api/pushes1817=== CONT TestPush_RejectsBadRequests/root_not_in_objects18182026/10/05 11:18:45 INFO Received push request method=POST path=/api/pushes1819=== CONT TestPush_RejectsBadRequests/no_roots18202026/10/05 11:18:45 INFO Received push request method=POST path=/api/pushes1821=== CONT TestPush_RejectsBadRequests/bad_root18222026/10/05 11:18:45 INFO Received push request method=POST path=/api/pushes1823=== CONT TestServerTLSConfig/no_client_CA1824--- PASS: TestPush_RejectsBadRequests (0.38s)1825 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1826 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1827 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1828 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1829=== CONT TestServerTLSConfig/not_a_PEM_file1830=== CONT TestServerTLSConfig/missing_CA_file1831--- PASS: TestServerTLSConfig (0.00s)1832 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1833 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1834 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)18352026/10/05 11:18:45 INFO Received push request method=POST path=/api/pushes18362026/10/05 11:18:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18372026/10/05 11:18:45 INFO Uploading 1ff25m39g9g4lrwvb84swq70hw737435-file1.txt (160B)18382026/10/05 11:18:45 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18392026/10/05 11:18:45 WARN Failed to register uploaded object key=1ff25m39g9g4lrwvb84swq70hw737435.ls error="server returned 404: 404 page not found\n"18402026/10/05 11:18:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18412026/10/05 11:18:45 INFO Signed narinfos id=1 count=118422026/10/05 11:18:45 INFO Uploading 1 narinfos18432026/10/05 11:18:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.552909ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18442026/10/05 11:18:45 INFO Received complete push request method=POST path=/api/pushes/1/complete18452026/10/05 11:18:45 WARN Failed to register uploaded object key=1ff25m39g9g4lrwvb84swq70hw737435.narinfo error="server returned 404: 404 page not found\n"18462026/10/05 11:18:45 INFO Upload complete. (66ms)1847--- PASS: TestReadProxy404 (0.35s)1848=== NAME TestNARDeduplicationMetadataUploadBug1849 metadata_upload_test.go:54: Retrieved narinfo from S3:1850 StorePath: /build/TestNARDeduplicationMetadataUploadBug592579886/001/store/1ff25m39g9g4lrwvb84swq70hw737435-file1.txt1851 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1852 Compression: zstd1853 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1854 NarSize: 1601855 References: 1856 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18572026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures1858 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1859 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1860 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18612026/10/05 11:18:45 INFO Aborted multipart uploads count=0 kept=018622026/10/05 11:18:45 WARN Force mode enabled - objects will be deleted immediately without grace period18632026/10/05 11:18:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=018642026/10/05 11:18:45 INFO Vacuumed table table=pending_closures18652026/10/05 11:18:45 INFO Vacuumed table table=pending_objects18662026/10/05 11:18:45 INFO Vacuumed table table=multipart_uploads18672026/10/05 11:18:45 INFO Vacuumed table table=closures18682026/10/05 11:18:45 INFO Vacuumed table table=objects18692026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures1870 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug592579886/001/store/jzil8f298k5jzbqf39wwd8lv7qm7n3kp-file2.txt18712026/10/05 11:18:45 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"18722026/10/05 11:18:45 INFO Received uploads request method=POST path=/api/pending_closures18732026/10/05 11:18:45 INFO Aborted multipart uploads count=0 kept=018742026/10/05 11:18:45 WARN Force mode enabled - objects will be deleted immediately without grace period18752026/10/05 11:18: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=018762026/10/05 11:18:45 INFO Vacuumed table table=pending_closures18772026/10/05 11:18:45 INFO Vacuumed table table=pending_objects18782026/10/05 11:18:45 INFO Vacuumed table table=multipart_uploads18792026/10/05 11:18:45 INFO Vacuumed table table=closures18802026/10/05 11:18:45 INFO Vacuumed table table=objects1881--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1882 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.37s)1883 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.40s)18842026/10/05 11:18:45 INFO Received push request method=POST path=/api/pushes18852026/10/05 11:18:45 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18862026/10/05 11:18:45 INFO Aborted multipart uploads count=0 kept=018872026/10/05 11:18:45 WARN Force mode enabled - objects will be deleted immediately without grace period18882026/10/05 11:18:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18892026/10/05 11:18:45 WARN Failed to register uploaded object key=jzil8f298k5jzbqf39wwd8lv7qm7n3kp.ls error="server returned 404: 404 page not found\n"18902026/10/05 11:18:45 INFO Signed narinfos id=2 count=118912026/10/05 11:18:45 INFO Uploading 1 narinfos18922026/10/05 11:18:45 INFO Received complete push request method=POST path=/api/pushes/2/complete18932026/10/05 11:18:45 WARN Failed to register uploaded object key=jzil8f298k5jzbqf39wwd8lv7qm7n3kp.narinfo error="server returned 404: 404 page not found\n"18942026/10/05 11:18:45 INFO Upload complete. (49ms)18952026/10/05 11:18:45 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36301/bucket88/?delete=\": context canceled"1896=== NAME TestNARDeduplicationMetadataUploadBug1897 metadata_upload_test.go:76: Retrieved narinfo from S3:1898 StorePath: /build/TestNARDeduplicationMetadataUploadBug592579886/001/store/jzil8f298k5jzbqf39wwd8lv7qm7n3kp-file2.txt1899 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1900 Compression: zstd1901 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1902 NarSize: 1601903 References: 1904 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1905 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1906 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1907 {"version":1,"root":{"type":"regular","size":44}}1908--- PASS: TestNARDeduplicationMetadataUploadBug (0.61s)19092026/10/05 11:18:45 INFO Aborted multipart uploads count=0 kept=019102026/10/05 11:18:45 WARN Force mode enabled - objects will be deleted immediately without grace period19112026-10-05 11:18:45.783 UTC [1729] ERROR: canceling statement due to user request19122026-10-05 11:18:45.783 UTC [1729] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block19132026-10-05 11:18:45.783 UTC [1729] STATEMENT: -- name: MarkStaleObjects :execrows1914 WITH RECURSIVE ct AS (1915 SELECT timezone('UTC', now()) AS now1916 ),1917 closure_reach AS (1918 -- Start with all closure keys1919 SELECT o.key, o.refs1920 FROM objects o1921 INNER JOIN closures c ON o.key = c.key1922 UNION1923 -- Recursively add all referenced objects1924 SELECT o.key, o.refs1925 FROM objects o1926 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1927 ),1928 reachable_objects AS (1929 SELECT DISTINCT key FROM closure_reach1930 ),1931 stale_objects AS (1932 SELECT o.key1933 FROM objects AS o, ct1934 WHERE1935 NOT EXISTS (1936 SELECT 11937 FROM reachable_objects ro1938 WHERE ro.key = o.key1939 )1940 AND NOT EXISTS (1941 SELECT 11942 FROM pending_objects AS po1943 WHERE po.key = o.key1944 )1945 AND o.deleted_at IS NULL -- Only mark fresh objects1946 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1947 FOR UPDATE1948 )1949 UPDATE objects1950 SET1951 deleted_at = ct.now,1952 first_deleted_at = COALESCE(first_deleted_at, ct.now)1953 FROM stale_objects, ct1954 WHERE objects.key = stale_objects.key1955 1956--- PASS: TestGCEndsOnShutdown (0.01s)1957 --- PASS: TestGCEndsOnShutdown/before_the_run (0.36s)1958 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.35s)1959 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.36s)19602026/10/05 11:18:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.625755ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19612026/10/05 11:18:45 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161962--- PASS: TestReadProxyNarinfo (0.54s)19632026/10/05 11:18:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19642026/10/05 11:18:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19652026/10/05 11:18:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=806.664621ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19662026/10/05 11:18:46 INFO lead: released remote=192.0.2.1:12341967--- PASS: TestLeadElectsOneAndHandsOver (3.13s)1968=== NAME TestOrphanedObjectsGCStressTest1969 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1970 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19712026/10/05 11:18:46 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01972=== NAME TestClientIntegration1973 client_integration_test.go:323: Objects in database after GC:1974 client_integration_test.go:323: Successfully deleted all objects with GC --force1975--- PASS: TestClientIntegration (2.66s)1976--- PASS: TestPendingClosureWriteTimeout (0.01s)1977 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1978 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1979 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1980 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.14s)19812026/10/05 11:18:46 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019822026/10/05 11:18:46 INFO Received create pin request method=POST path=/api/pins/myapp19832026/10/05 11:18:46 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2814019402/001/store/8cnp2qfyd4y06czq2m9vi7rcb4q6b97r-pinned-file.txt narinfo_key=8cnp2qfyd4y06czq2m9vi7rcb4q6b97r.narinfo19842026/10/05 11:18:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures19852026/10/05 11:18:46 INFO Garbage collection started19862026/10/05 11:18:46 INFO Aborted multipart uploads count=0 kept=019872026/10/05 11:18:46 WARN Force mode enabled - objects will be deleted immediately without grace period19882026/10/05 11:18: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=019892026/10/05 11:18:46 INFO Vacuumed table table=pending_closures19902026/10/05 11:18:46 INFO Vacuumed table table=pending_objects19912026/10/05 11:18:46 INFO Vacuumed table table=multipart_uploads19922026/10/05 11:18:46 INFO Vacuumed table table=closures19932026/10/05 11:18:46 INFO Vacuumed table table=objects1994--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)1995 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1996 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1997 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.99s)1998=== NAME TestOrphanedObjectsGCStressTest1999 orphaned_objects_gc_test.go:509: Stress test completed successfully:2000 orphaned_objects_gc_test.go:510: - Active objects preserved: 202001 orphaned_objects_gc_test.go:511: - Objects deleted: 2102002 orphaned_objects_gc_test.go:512: - Total GC'd: 2102003--- PASS: TestOrphanedObjectsGCStressTest (2.08s)20042026/10/05 11:18:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.718986337s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20052026/10/05 11:18:47 WARN Rate limiter enabled after throttle name=s3-test rate=520062026/10/05 11:18:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2007=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2008 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102009 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002010--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.79s)2011=== NAME TestPinProtectsFromGC2012 client_integration_test.go:840: Pin successfully protected closure from garbage collection2013--- PASS: TestPinProtectsFromGC (4.84s)2014--- PASS: TestConnectWaitsForAPeerMigration (5.32s)20152026/10/05 11:18:48 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20162026/10/05 11:18:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.18861ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20172026/10/05 11:18:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.242004ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20182026/10/05 11:18:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=793.128708ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2019--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.56s)20202026/10/05 11:18:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.509003745s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20212026/10/05 11:18:51 INFO Aborted multipart uploads count=1 kept=020222026/10/05 11:18:51 INFO Received cleanup request method=DELETE path=/api/pending_closures20232026/10/05 11:18:51 INFO Aborted multipart uploads count=1 kept=02024--- PASS: TestPendingCleanupUsesOneCutoff (6.38s)20252026/10/05 11:18:51 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"20262026/10/05 11:18:51 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/05 11:18:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.669263ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/05 11:18:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.216112ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/05 11:18:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=811.896496ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20302026/10/05 11:18:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.510866673s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/05 11:18:54 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20322026/10/05 11:18:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.144683ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20332026/10/05 11:18:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=367.556028ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20342026/10/05 11:18:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=792.600343ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20352026/10/05 11:18:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.587552306s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2036--- PASS: TestClientErrorHandling (0.00s)2037 --- PASS: TestClientErrorHandling/InvalidStorePath (0.37s)2038 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)2039 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.43s)2040PASS20412026-10-05 11:18:58.119 UTC [129] LOG: received smart shutdown request20422026-10-05 11:18:58.125 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120432026-10-05 11:18:58.137 UTC [134] LOG: shutting down20442026-10-05 11:18:58.138 UTC [134] LOG: checkpoint starting: shutdown immediate20452026-10-05 11:18:59.039 UTC [134] LOG: checkpoint complete: wrote 11091 buffers (67.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.207 s, sync=0.669 s, total=0.902 s; sync files=31000, longest=0.038 s, average=0.001 s; distance=428459 kB, estimate=428459 kB; lsn=0/1B9D0998, redo lsn=0/1B9D099820462026-10-05 11:18:59.117 UTC [129] LOG: database system is shut down2047Running OIDC tests...2048=== RUN TestAudienceForIssuer2049=== PAUSE TestAudienceForIssuer2050=== RUN TestGlobMatch2051=== PAUSE TestGlobMatch2052=== RUN TestValidateToken_ValidToken2053=== PAUSE TestValidateToken_ValidToken2054=== RUN TestValidateToken_WrongAudience2055=== PAUSE TestValidateToken_WrongAudience2056=== RUN TestValidateToken_Expired2057=== PAUSE TestValidateToken_Expired2058=== RUN TestValidateToken_BoundClaimsMismatch2059=== PAUSE TestValidateToken_BoundClaimsMismatch2060=== RUN TestValidateToken_BoundSubjectMismatch2061=== PAUSE TestValidateToken_BoundSubjectMismatch2062=== RUN TestValidateToken_MultipleProviders2063=== PAUSE TestValidateToken_MultipleProviders2064=== RUN TestValidateToken_NoMatchingProvider2065=== PAUSE TestValidateToken_NoMatchingProvider2066=== RUN TestValidateToken_KubernetesServiceAccount2067=== PAUSE TestValidateToken_KubernetesServiceAccount2068=== RUN TestNewValidator_KubernetesRequiresCA2069=== PAUSE TestNewValidator_KubernetesRequiresCA2070=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2071=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2072=== RUN TestPins_ReservedForMatchingRule2073=== PAUSE TestPins_ReservedForMatchingRule2074=== RUN TestPins_TopLevelShorthand2075=== PAUSE TestPins_TopLevelShorthand2076=== RUN TestPins_ConfigValidation2077=== PAUSE TestPins_ConfigValidation2078=== RUN TestScopes_LegacyProviderDefaultsToWrite2079=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2080=== RUN TestScopes_Rules2081=== PAUSE TestScopes_Rules2082=== RUN TestScopes_ConfigValidation2083=== PAUSE TestScopes_ConfigValidation2084=== CONT TestAudienceForIssuer2085=== CONT TestPins_ConfigValidation2086=== CONT TestValidateToken_KubernetesServiceAccount2087=== CONT TestPins_ReservedForMatchingRule2088--- PASS: TestAudienceForIssuer (0.00s)2089=== CONT TestValidateToken_NoMatchingProvider2090=== CONT TestValidateToken_MultipleProviders2091=== CONT TestValidateToken_BoundSubjectMismatch2092=== CONT TestValidateToken_BoundClaimsMismatch2093=== CONT TestValidateToken_Expired2094=== CONT TestValidateToken_WrongAudience2095--- PASS: TestPins_ConfigValidation (0.00s)2096=== CONT TestValidateToken_ValidToken2097=== CONT TestGlobMatch2098=== RUN TestGlobMatch/foo_foo2099=== PAUSE TestGlobMatch/foo_foo2100=== RUN TestGlobMatch/foo_bar2101=== PAUSE TestGlobMatch/foo_bar2102=== RUN TestGlobMatch/*_2103=== CONT TestScopes_Rules2104=== CONT TestScopes_ConfigValidation2105=== CONT TestPins_TopLevelShorthand2106=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2107=== CONT TestScopes_LegacyProviderDefaultsToWrite2108--- PASS: TestScopes_ConfigValidation (0.00s)2109=== CONT TestNewValidator_KubernetesRequiresCA2110=== PAUSE TestGlobMatch/*_2111=== RUN TestGlobMatch/*_anything2112=== PAUSE TestGlobMatch/*_anything2113=== RUN TestGlobMatch/foo*_foo2114=== PAUSE TestGlobMatch/foo*_foo2115=== RUN TestGlobMatch/foo*_foobar2116=== PAUSE TestGlobMatch/foo*_foobar2117=== RUN TestGlobMatch/foo*_bar2118=== PAUSE TestGlobMatch/foo*_bar2119=== RUN TestGlobMatch/*bar_bar2120=== PAUSE TestGlobMatch/*bar_bar2121=== RUN TestGlobMatch/*bar_foobar2122=== PAUSE TestGlobMatch/*bar_foobar2123=== RUN TestGlobMatch/*bar_foo2124=== PAUSE TestGlobMatch/*bar_foo2125=== RUN TestGlobMatch/foo*bar_foobar2126=== PAUSE TestGlobMatch/foo*bar_foobar2127=== RUN TestGlobMatch/foo*bar_foo123bar2128=== PAUSE TestGlobMatch/foo*bar_foo123bar2129=== RUN TestGlobMatch/foo*bar_foobarbaz2130=== PAUSE TestGlobMatch/foo*bar_foobarbaz2131=== RUN TestGlobMatch/*/*_foo/bar2132=== PAUSE TestGlobMatch/*/*_foo/bar2133=== RUN TestGlobMatch/*/*_foo2134=== PAUSE TestGlobMatch/*/*_foo2135=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2136=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2137=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02138=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02139=== RUN TestGlobMatch/refs/*/main_refs/heads/main2140=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2141=== RUN TestGlobMatch/fo?_foo2142=== PAUSE TestGlobMatch/fo?_foo2143=== RUN TestGlobMatch/fo?_fo2144=== PAUSE TestGlobMatch/fo?_fo2145=== RUN TestGlobMatch/fo?_fooo2146=== PAUSE TestGlobMatch/fo?_fooo2147=== RUN TestGlobMatch/?oo_foo2148=== PAUSE TestGlobMatch/?oo_foo2149=== RUN TestGlobMatch/?oo_boo2150=== PAUSE TestGlobMatch/?oo_boo2151=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2152=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2153=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2154=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2155=== CONT TestGlobMatch/foo_foo2156=== CONT TestGlobMatch/?oo_foo2157=== CONT TestGlobMatch/fo?_fooo2158=== CONT TestGlobMatch/fo?_fo2159=== CONT TestGlobMatch/fo?_foo2160=== CONT TestGlobMatch/refs/*/main_refs/heads/main2161=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02162=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2163=== CONT TestGlobMatch/*/*_foo2164=== CONT TestGlobMatch/*/*_foo/bar2165=== CONT TestGlobMatch/foo*bar_foobarbaz2166=== CONT TestGlobMatch/foo*bar_foo123bar2167=== CONT TestGlobMatch/foo*bar_foobar2168=== CONT TestGlobMatch/*bar_foo2169=== CONT TestGlobMatch/*bar_foobar2170=== CONT TestGlobMatch/*bar_bar2171=== CONT TestGlobMatch/foo*_bar2172=== CONT TestGlobMatch/foo*_foobar2173=== CONT TestGlobMatch/foo*_foo2174=== CONT TestGlobMatch/*_anything2175=== CONT TestGlobMatch/*_2176=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2177=== CONT TestGlobMatch/?oo_boo2178=== CONT TestGlobMatch/foo_bar2179=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2180--- PASS: TestGlobMatch (0.00s)2181 --- PASS: TestGlobMatch/foo_foo (0.00s)2182 --- PASS: TestGlobMatch/?oo_foo (0.00s)2183 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2184 --- PASS: TestGlobMatch/fo?_fo (0.00s)2185 --- PASS: TestGlobMatch/fo?_foo (0.00s)2186 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2187 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2188 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2189 --- PASS: TestGlobMatch/*/*_foo (0.00s)2190 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2191 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2192 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2193 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2194 --- PASS: TestGlobMatch/*bar_foo (0.00s)2195 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2196 --- PASS: TestGlobMatch/*bar_bar (0.00s)2197 --- PASS: TestGlobMatch/foo*_bar (0.00s)2198 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2199 --- PASS: TestGlobMatch/foo*_foo (0.00s)2200 --- PASS: TestGlobMatch/*_anything (0.00s)2201 --- PASS: TestGlobMatch/*_ (0.00s)2202 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2203 --- PASS: TestGlobMatch/?oo_boo (0.00s)2204 --- PASS: TestGlobMatch/foo_bar (0.00s)2205 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)22062026/10/05 11:19:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38225/oidc2207--- PASS: TestValidateToken_ValidToken (0.04s)22082026/10/05 11:19:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37763/oidc22092026/10/05 11:19:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232210--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)2211--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)22122026/10/05 11:19:00 http: TLS handshake error from 127.0.0.1:35558: remote error: tls: bad certificate2213--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)22142026/10/05 11:19:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37447/oidc22152026/10/05 11:19:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40845/oidc2216--- PASS: TestPins_TopLevelShorthand (0.12s)22172026/10/05 11:19:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36651/oidc2218--- PASS: TestValidateToken_Expired (0.13s)2219--- PASS: TestScopes_Rules (0.13s)22202026/10/05 11:19:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:392072221--- PASS: TestValidateToken_KubernetesServiceAccount (0.14s)22222026/10/05 11:19:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43011/oidc2223--- PASS: TestValidateToken_WrongAudience (0.15s)22242026/10/05 11:19:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35503/oidc2225--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.22s)22262026/10/05 11:19:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42603/oidc22272026/10/05 11:19:01 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35479/oidc2228--- PASS: TestValidateToken_MultipleProviders (0.23s)22292026/10/05 11:19:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44763/oidc2230--- PASS: TestValidateToken_BoundClaimsMismatch (0.25s)22312026/10/05 11:19:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40733/oidc2232--- PASS: TestValidateToken_NoMatchingProvider (0.28s)22332026/10/05 11:19:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42847/oidc2234--- PASS: TestPins_ReservedForMatchingRule (0.29s)2235PASS2236Running hook tests...2237=== RUN TestSendPathsEmpty2238=== PAUSE TestSendPathsEmpty2239=== RUN TestQueueEnqueueAndFetch2240=== PAUSE TestQueueEnqueueAndFetch2241=== RUN TestQueueDeduplication2242=== PAUSE TestQueueDeduplication2243=== RUN TestQueueRemove2244=== PAUSE TestQueueRemove2245=== RUN TestQueueFetchBatchLimit2246=== PAUSE TestQueueFetchBatchLimit2247=== RUN TestQueueRetryMovesToBack2248=== PAUSE TestQueueRetryMovesToBack2249=== RUN TestQueueFetchRemoveLifecycle2250=== PAUSE TestQueueFetchRemoveLifecycle2251=== RUN TestQueueConcurrentWriters2252=== PAUSE TestQueueConcurrentWriters2253=== RUN TestQueueRemoveLargeClosure2254=== PAUSE TestQueueRemoveLargeClosure2255=== RUN TestServerClientIntegration2256=== PAUSE TestServerClientIntegration2257=== RUN TestServerQueueError2258=== PAUSE TestServerQueueError2259=== RUN TestGetListenerSocketActivation2260 server_test.go:210: === RUN TestGetListenerSocketActivation2261 --- PASS: TestGetListenerSocketActivation (0.00s)2262 PASS2263 2264--- PASS: TestGetListenerSocketActivation (0.01s)2265=== RUN TestDrainIsolatesPoisonPath2266=== PAUSE TestDrainIsolatesPoisonPath2267=== RUN TestRunNotBlockedByPoisonHead2268=== PAUSE TestRunNotBlockedByPoisonHead2269=== RUN TestDrainGivesUpWhenServerDown2270=== PAUSE TestDrainGivesUpWhenServerDown2271=== RUN TestFailedPathPrunedByLaterClosure2272=== PAUSE TestFailedPathPrunedByLaterClosure2273=== RUN TestWorkerUploadsAndRemoves2274=== PAUSE TestWorkerUploadsAndRemoves2275=== RUN TestWorkerSkipsGCdPaths2276=== PAUSE TestWorkerSkipsGCdPaths2277=== RUN TestWorkerPrunesClosureDeps2278=== PAUSE TestWorkerPrunesClosureDeps2279=== RUN TestDrainTimeout2280=== PAUSE TestDrainTimeout2281=== CONT TestSendPathsEmpty2282=== CONT TestWorkerSkipsGCdPaths2283=== CONT TestDrainTimeout2284--- PASS: TestSendPathsEmpty (0.00s)2285=== CONT TestQueueConcurrentWriters2286=== CONT TestQueueFetchRemoveLifecycle2287=== CONT TestQueueRetryMovesToBack2288=== CONT TestQueueFetchBatchLimit2289=== CONT TestQueueRemove2290=== CONT TestQueueDeduplication2291=== CONT TestQueueEnqueueAndFetch2292=== CONT TestRunNotBlockedByPoisonHead2293=== CONT TestWorkerUploadsAndRemoves2294=== CONT TestFailedPathPrunedByLaterClosure2295=== CONT TestDrainGivesUpWhenServerDown2296=== CONT TestServerQueueError2297=== CONT TestDrainIsolatesPoisonPath2298=== CONT TestServerClientIntegration2299=== CONT TestWorkerPrunesClosureDeps2300=== CONT TestQueueRemoveLargeClosure23012026/10/05 11:19:01 ERROR Failed to queue paths error="permission denied" count=12302--- PASS: TestServerQueueError (0.00s)2303--- PASS: TestServerClientIntegration (0.00s)23042026/10/05 11:19:01 INFO Upload queue status pending=323052026/10/05 11:19:01 INFO Uploading batch count=123062026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=123072026/10/05 11:19:01 INFO Uploading batch count=123082026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=123092026/10/05 11:19:01 INFO Upload queue status pending=223102026/10/05 11:19:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4168781098/002/nonexistent23112026/10/05 11:19:01 INFO Upload queue status pending=223122026/10/05 11:19:01 INFO Uploading batch count=223132026/10/05 11:19:01 INFO Uploading batch count=123142026/10/05 11:19:01 INFO Uploading batch count=223152026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=223162026/10/05 11:19:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2325248962/002/a23172026/10/05 11:19:01 INFO Uploading batch count=22318--- PASS: TestQueueEnqueueAndFetch (0.01s)2319--- PASS: TestQueueFetchBatchLimit (0.01s)23202026/10/05 11:19:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2325248962/002/b2321--- PASS: TestQueueRemove (0.01s)23222026/10/05 11:19:01 INFO Upload queue status pending=223232026/10/05 11:19:01 INFO Uploading batch count=12324--- PASS: TestQueueDeduplication (0.02s)23252026/10/05 11:19:01 INFO Uploading batch count=423262026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=423272026/10/05 11:19:01 INFO Uploading batch count=223282026/10/05 11:19:01 INFO Uploading batch count=123292026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=223302026/10/05 11:19:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2325248962/002/c2331--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23322026/10/05 11:19:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath557705399/002/bbb23332026/10/05 11:19:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2325248962/002/d23342026/10/05 11:19:01 INFO Uploading batch count=12335--- PASS: TestQueueRetryMovesToBack (0.02s)23362026/10/05 11:19:01 INFO Uploading batch count=223372026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=223382026/10/05 11:19:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2325248962/002/e23392026/10/05 11:19:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2325248962/002/f23402026/10/05 11:19:01 INFO Uploading batch count=123412026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=123422026/10/05 11:19:01 ERROR Drain finished with paths left in queue remaining=1023432026/10/05 11:19:01 INFO Uploading batch count=123442026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=12345--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23462026/10/05 11:19:01 INFO Uploading batch count=123472026/10/05 11:19:01 ERROR Upload failed error="upload failed" count=123482026/10/05 11:19:01 ERROR Drain finished with paths left in queue remaining=12349--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2350--- PASS: TestDrainIsolatesPoisonPath (0.02s)2351--- PASS: TestWorkerUploadsAndRemoves (0.03s)2352--- PASS: TestWorkerSkipsGCdPaths (0.04s)2353--- PASS: TestWorkerPrunesClosureDeps (0.03s)2354--- PASS: TestQueueRemoveLargeClosure (0.14s)2355--- PASS: TestQueueConcurrentWriters (0.17s)23562026/10/05 11:19:01 ERROR Upload failed error="context deadline exceeded" count=223572026/10/05 11:19:01 ERROR Drain finished with paths left in queue remaining=42358--- PASS: TestDrainTimeout (0.22s)23592026/10/05 11:19:02 INFO Uploading batch count=123602026/10/05 11:19:02 INFO Uploading batch count=123612026/10/05 11:19:02 INFO Uploading batch count=123622026/10/05 11:19:02 ERROR Upload failed error="upload failed" count=123632026/10/05 11:19:02 INFO Uploading batch count=123642026/10/05 11:19:02 ERROR Upload failed error="upload failed" count=123652026/10/05 11:19:02 INFO Uploading batch count=123662026/10/05 11:19:02 ERROR Upload failed error="upload failed" count=123672026/10/05 11:19:02 INFO Uploading batch count=123682026/10/05 11:19:02 ERROR Upload failed error="upload failed" count=123692026/10/05 11:19:02 ERROR Drain finished with paths left in queue remaining=12370--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2371PASS