niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #356
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestScriptTokenEmptyCommand102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestEncodeNixBase32104=== RUN TestEncodeNixBase32/test_string_hash105=== PAUSE TestEncodeNixBase32/test_string_hash106=== RUN TestEncodeNixBase32/empty_input107=== CONT TestPathInfoHashCompatibility108=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)109=== CONT TestSetClientTLSDoesNotMutateDefaultTransport110=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)111=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon112=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon113=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI114=== CONT TestGetStorePathHash115=== RUN TestGetStorePathHash/valid_store_path116=== PAUSE TestGetStorePathHash/valid_store_path117=== RUN TestGetStorePathHash/basename_without_hyphen_should_error118=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error119=== CONT TestScriptTokenScriptFails120=== CONT TestConvertHashToNix32121=== RUN TestConvertHashToNix32/SRI_format_to_Nix32122=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32123=== RUN TestConvertHashToNix32/already_Nix32_format124=== PAUSE TestConvertHashToNix32/already_Nix32_format125=== RUN TestConvertHashToNix32/invalid_format126=== PAUSE TestConvertHashToNix32/invalid_format127=== CONT TestStreamPushReportsEveryPath128=== CONT TestScriptTokenBadJSON129=== CONT TestEncodeNixBase32WithRealHash130--- PASS: TestEncodeNixBase32WithRealHash (0.00s)131=== CONT TestScriptTokenEmptyToken132=== CONT TestStreamPushGivesUpOnDeadServer133=== CONT TestScriptTokenCachesUntilRefresh134=== CONT TestSetClientTLS135=== CONT TestScriptTokenNoExpiryRerunsEveryCall136=== CONT TestClientSignaturesByStorePath137=== CONT TestFileTokenEmpty138=== CONT TestStreamPushReportsSignatures139=== CONT TestFileTokenMissing140=== CONT TestParsePathInfoJSON141=== CONT TestStreamPushRequestLine142=== CONT TestSetClientTLSErrors143=== CONT TestResolveStorePath144=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess145=== PAUSE TestEncodeNixBase32/empty_input146=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI147=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error148=== CONT TestRateLimiterFeedback149=== RUN TestRateLimiterFeedback/429_enables_limiter150=== PAUSE TestRateLimiterFeedback/429_enables_limiter151=== RUN TestRateLimiterFeedback/503_enables_limiter152=== PAUSE TestRateLimiterFeedback/503_enables_limiter153=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter154=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter155=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter156--- PASS: TestScriptTokenScriptFails (0.00s)157=== CONT TestPathInfoCACompatibility158--- PASS: TestClientSignaturesByStorePath (0.00s)159=== RUN TestPathInfoCACompatibility/null_ca_field160=== PAUSE TestPathInfoCACompatibility/null_ca_field161=== RUN TestPathInfoCACompatibility/old_string_format_-_text162=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1632026/10/04 20:06:43 ERROR Upload failed error="connection refused" count=20164=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1652026/10/04 20:06:43 ERROR Server seems unavailable, giving up on batch untried=17166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive167=== RUN TestParsePathInfoJSON/Nix_format168=== CONT TestParsePathInfoJSONMultiplePaths169=== CONT TestStreamPushIsolatesFailures170=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512171=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths172=== PAUSE TestParsePathInfoJSON/Nix_format173=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths174=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121752026/10/04 20:06:43 WARN Rate limiter enabled after throttle name=server-test rate=5176--- PASS: TestStreamPushReportsEveryPath (0.00s)177=== CONT TestUploadMultipart_PartsInParallel178--- PASS: TestFileTokenEmpty (0.00s)179=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1802026/10/04 20:06:43 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43005181=== RUN TestParsePathInfoJSON/Lix_format182=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths183=== CONT TestDumpPathWriterError184=== CONT TestDumpPathSingleFile185--- PASS: TestFileTokenMissing (0.00s)186=== CONT TestFileTokenReadsAndCaches1872026/10/04 20:06:43 WARN Rate limiter backed off name=server-test rate=51882026/10/04 20:06:43 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43005189--- PASS: TestScriptTokenEmptyToken (0.00s)190=== CONT TestUploadMultipart_SupersededByPeer191=== RUN TestUploadMultipart_SupersededByPeer/exists192=== CONT TestDumpPathMatchesNix1932026/10/04 20:06:43 ERROR Upload failed error=boom count=1194=== RUN TestSetClientTLSErrors/missing_cert_file195=== PAUSE TestSetClientTLSErrors/missing_cert_file196=== RUN TestSetClientTLSErrors/missing_key_file197=== PAUSE TestSetClientTLSErrors/missing_key_file198=== RUN TestSetClientTLSErrors/missing_ca_file199=== PAUSE TestSetClientTLSErrors/missing_ca_file200--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)201--- PASS: TestFileTokenReadsAndCaches (0.00s)202=== PAUSE TestParsePathInfoJSON/Lix_format2032026/10/04 20:06:43 WARN Rate limiter enabled after throttle name=server-test rate=5204=== CONT TestPartSizeForNAR2052026/10/04 20:06:43 ERROR Upload failed error="bad path" count=3206=== PAUSE TestUploadMultipart_SupersededByPeer/exists207=== RUN TestPathInfoCACompatibility/new_structured_format_-_text208=== RUN TestParsePathInfoJSON/empty_input209=== CONT TestStreamPushBatchesUnderLoad210=== CONT TestCaseHackSuffix211=== RUN TestSetClientTLSErrors/invalid_ca_file212=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun213--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)214=== RUN TestPartSizeForNAR/zero_stays_at_minimum215=== PAUSE TestSetClientTLSErrors/invalid_ca_file216--- PASS: TestStreamPushIsolatesFailures (0.00s)217--- PASS: TestScriptTokenBadJSON (0.00s)218=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica219=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== PAUSE TestPartSizeForNAR/small_stays_at_minimum222=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum223=== RUN TestSetClientTLS/rejects_connection_without_client_cert224=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert225=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA226=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA227=== RUN TestSetClientTLS/preserves_debug_logging_transport228=== PAUSE TestSetClientTLS/preserves_debug_logging_transport229=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error230--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)231=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths232=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error233=== CONT TestRegisterUploadedObjectReusesConnections2342026/10/04 20:06:43 ERROR Upload failed error=boom count=1235--- PASS: TestStreamPushReportsSignatures (0.01s)236=== CONT TestShellSplitErrors237--- PASS: TestShellSplitErrors (0.00s)238=== CONT TestConvertHashToNix32/SRI_format_to_Nix32239=== CONT TestStaticToken240=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text241=== RUN TestUploadMultipart_SupersededByPeer/missing242=== PAUSE TestUploadMultipart_SupersededByPeer/missing243=== CONT TestFilterOversizedClosures244=== CONT TestConvertHashToNix32/invalid_format245=== RUN TestFilterOversizedClosures/no_limit_keeps_everything246=== CONT TestEncodeNixBase32/test_string_hash247=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything248=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped249=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error250=== CONT TestShellSplit251=== PAUSE TestParsePathInfoJSON/empty_input252=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum253=== CONT TestEncodeNixBase32/empty_input2542026/10/04 20:06:43 INFO Garbage collection started255=== CONT TestConvertHashToNix32/already_Nix32_format256--- PASS: TestEncodeNixBase32 (0.00s)257 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)258 --- PASS: TestEncodeNixBase32/empty_input (0.00s)259=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122602026/10/04 20:06:43 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=0261=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter262--- PASS: TestShellSplit (0.00s)263--- PASS: TestResolveStorePath (0.03s)264=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI265=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method266=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon267=== CONT TestRateLimiterFeedback/429_enables_limiter2682026/10/04 20:06:43 INFO Garbage collection started269--- PASS: TestDumpPathSingleFile (0.03s)270--- PASS: TestStaticToken (0.00s)271--- PASS: TestConvertHashToNix32 (0.00s)272 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)273 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)274 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)275=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)276=== CONT TestSetClientTLSErrors/missing_ca_file277=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped278=== RUN TestFilterOversizedClosures/all_closures_skipped279=== PAUSE TestFilterOversizedClosures/all_closures_skipped280=== RUN TestParsePathInfoJSON/whitespace_only281=== PAUSE TestParsePathInfoJSON/whitespace_only282=== CONT TestSetClientTLS/rejects_connection_without_client_cert2832026/10/04 20:06:43 WARN Rate limiter enabled after throttle name=server-test rate=5284=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2852026/10/04 20:06:43 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:464192862026/10/04 20:06:43 WARN Rate limiter backed off name=server-test rate=5287=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths288=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths289=== CONT TestUploadMultipart_SupersededByPeer/exists2902026/10/04 20:06:43 WARN Garbage collection finished on another replica. Its statistics are not available here291=== CONT TestUploadMultipart_SupersededByPeer/missing292=== RUN TestParsePathInfoJSON/invalid_JSON293=== PAUSE TestParsePathInfoJSON/invalid_JSON294=== CONT TestRateLimiterFeedback/503_enables_limiter295=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts296=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts297=== RUN TestPartSizeForNAR/1_TiB298=== PAUSE TestPartSizeForNAR/1_TiB299=== RUN TestPartSizeForNAR/5_TiB_S3_max_object300=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object301=== RUN TestPartSizeForNAR/capped_at_5_GiB302=== PAUSE TestPartSizeForNAR/capped_at_5_GiB303=== CONT TestSetClientTLSErrors/missing_cert_file304=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error305=== CONT TestGetStorePathHash/basename_without_hyphen_should_error306=== CONT TestFilterOversizedClosures/no_limit_keeps_everything307=== CONT TestFilterOversizedClosures/all_closures_skipped3082026/10/04 20:06:43 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=503092026/10/04 20:06:43 WARN Rate limiter enabled after throttle name=server-test rate=5310=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3112026/10/04 20:06:43 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:443633122026/10/04 20:06:43 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=2000313=== CONT TestParsePathInfoJSON/Nix_format314=== CONT TestParsePathInfoJSON/invalid_JSON315=== CONT TestParsePathInfoJSON/whitespace_only316=== CONT TestParsePathInfoJSON/empty_input317=== CONT TestParsePathInfoJSON/Lix_format318=== CONT TestPartSizeForNAR/zero_stays_at_minimum319=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error320=== CONT TestPartSizeForNAR/capped_at_5_GiB321=== CONT TestPartSizeForNAR/5_TiB_S3_max_object322=== CONT TestPartSizeForNAR/1_TiB323=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts324=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum325=== CONT TestPartSizeForNAR/small_stays_at_minimum326--- PASS: TestDoServerRequestAttachesToken (0.04s)327--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)328=== CONT TestSetClientTLSErrors/invalid_ca_file329=== CONT TestSetClientTLSErrors/missing_key_file330=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter331=== CONT TestSetClientTLS/preserves_debug_logging_transport332=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method333=== CONT TestGetStorePathHash/valid_store_path334--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)3352026/10/04 20:06:43 WARN Rate limiter backed off name=server-test rate=5336=== CONT TestPathInfoCACompatibility/null_ca_field337--- PASS: TestPathInfoHashCompatibility (0.00s)338 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)339 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)340 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)341 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)342--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)343 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)344 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)345--- PASS: TestFilterOversizedClosures (0.03s)346 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)347 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)348 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)349--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)350--- PASS: TestSetClientTLSErrors (0.00s)351 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)352 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)353 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)354 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)355=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method356--- PASS: TestParsePathInfoJSON (0.04s)357 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)358 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)359 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)360 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)361 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)362--- PASS: TestGetStorePathHash (0.01s)363 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)364 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)365 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)366 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)367--- PASS: TestPartSizeForNAR (0.03s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)370 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)371 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)372 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)373 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)375=== CONT TestPathInfoCACompatibility/new_structured_format_-_text376=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive377=== CONT TestPathInfoCACompatibility/old_string_format_-_text378--- PASS: TestPathInfoCACompatibility (0.04s)379 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)380 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)381 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)382 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)383 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)384--- PASS: TestRateLimiterFeedback (0.00s)385 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)387 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)388 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)389--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)390--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)391 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)392 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)3932026/10/04 20:06:43 http: TLS handshake error from 127.0.0.1:39310: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)398--- PASS: TestCaseHackSuffix (0.06s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)400--- PASS: TestStreamPushRequestLine (0.08s)401--- PASS: TestDumpPathWriterError (0.08s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.12s)404--- PASS: TestUploadMultipart_PartsInParallel (0.67s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres2756202457/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/postgres2756202457/data -l logfile start434435/build/postgres2756202457:5432 - no response4362026-10-04 20:06:45.432 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-04 20:06:45.432 UTC [128] LOG: listening on Unix socket "/build/postgres2756202457/.s.PGSQL.5432"4382026-10-04 20:06:45.436 UTC [135] LOG: database system was shut down at 2026-10-04 20:06:45 UTC4392026-10-04 20:06:45.439 UTC [128] LOG: database system is ready to accept connections440/build/postgres2756202457: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/04 20:06:45 INFO lead: acquired remote=192.0.2.1:12344872026/10/04 20:06:46 INFO lead: released remote=192.0.2.1:12344882026/10/04 20:06:46 INFO lead: acquired remote=192.0.2.1:12344892026/10/04 20:06:48 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (2.33s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestLeadEndsWhenItsConnectionHangs4942026/10/04 20:06:48 INFO lead: acquired remote=192.0.2.1:12344952026-10-04 20:06:49.561 UTC [386] FATAL: terminating connection due to administrator command4962026/10/04 20:06:49 INFO lead: acquired remote=192.0.2.1:12344972026/10/04 20:06:50 WARN lead: lock connection lost error="timeout: context deadline exceeded"4982026/10/04 20:06:50 INFO lead: released remote=192.0.2.1:12344992026/10/04 20:06:51 INFO lead: released remote=192.0.2.1:1234500--- PASS: TestLeadEndsWhenItsConnectionHangs (3.10s)501=== RUN TestGCAdvisoryLockBlocksConcurrentRun502=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun503=== RUN TestGCBugBareHashReferences504=== PAUSE TestGCBugBareHashReferences505=== RUN TestGCMetrics506=== PAUSE TestGCMetrics507=== RUN TestPushDedupSurvivesConcurrentGC508=== PAUSE TestPushDedupSurvivesConcurrentGC509=== RUN TestDeduplicatedObjectsRecordedAsPending510=== PAUSE TestDeduplicatedObjectsRecordedAsPending511=== RUN TestGCSweepSkipsPendingObjects512=== PAUSE TestGCSweepSkipsPendingObjects513=== RUN TestTombstonedObjectOfferedWithoutWaiting514=== PAUSE TestTombstonedObjectOfferedWithoutWaiting515=== RUN TestGCSweepDeliversEachKeyOnce516=== PAUSE TestGCSweepDeliversEachKeyOnce517=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection518=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection519=== RUN TestForceGCDuringPushOffersSweptObject520=== PAUSE TestForceGCDuringPushOffersSweptObject521=== RUN TestFailedS3DeleteKeepsTombstone522=== PAUSE TestFailedS3DeleteKeepsTombstone523=== RUN TestSweepSkipsRowsLockedByPush524=== PAUSE TestSweepSkipsRowsLockedByPush525=== RUN TestRegisterCompletedObjectNeedsPendingRow526=== PAUSE TestRegisterCompletedObjectNeedsPendingRow527=== RUN TestGetExistingObjectsLocksRows528=== PAUSE TestGetExistingObjectsLocksRows529=== RUN TestSweepRechecksPendingAfterLocking530=== PAUSE TestSweepRechecksPendingAfterLocking531=== RUN TestPushWaitsForSweepHoldingRow532=== PAUSE TestPushWaitsForSweepHoldingRow533=== RUN TestCommitRacingPendingCleanupKeepsObjects534=== PAUSE TestCommitRacingPendingCleanupKeepsObjects535=== RUN TestGCEndsOnShutdown536=== PAUSE TestGCEndsOnShutdown537=== RUN TestGCTaskStore_StartNew538=== PAUSE TestGCTaskStore_StartNew539=== RUN TestGCTaskStore_DeduplicateSameParams540=== PAUSE TestGCTaskStore_DeduplicateSameParams541=== RUN TestGCTaskStore_ConflictDifferentParams542=== PAUSE TestGCTaskStore_ConflictDifferentParams543=== RUN TestGCTaskStore_GetEmpty544=== PAUSE TestGCTaskStore_GetEmpty545=== RUN TestGCTaskStore_GetReturnsLatest546=== PAUSE TestGCTaskStore_GetReturnsLatest547=== RUN TestGCTaskStore_CompletedAllowsNewTask548=== PAUSE TestGCTaskStore_CompletedAllowsNewTask549=== RUN TestGCTaskStore_PhaseUpdates550=== PAUSE TestGCTaskStore_PhaseUpdates551=== RUN TestGCTaskStore_Fail552=== PAUSE TestGCTaskStore_Fail553=== RUN TestGracefulShutdownDrainsInflight554=== PAUSE TestGracefulShutdownDrainsInflight555=== RUN TestService_healthCheckHandler556=== PAUSE TestService_healthCheckHandler557=== RUN TestService_readinessHandler558=== PAUSE TestService_readinessHandler559=== RUN TestGenerateLandingPage560=== PAUSE TestGenerateLandingPage561=== RUN TestCacheConfigHandlerMaxNarSize562=== PAUSE TestCacheConfigHandlerMaxNarSize563=== RUN TestCreatePendingClosureRejectsOversizedNAR564=== PAUSE TestCreatePendingClosureRejectsOversizedNAR565=== RUN TestNARDeduplicationMetadataUploadBug566=== PAUSE TestNARDeduplicationMetadataUploadBug567=== RUN TestMetricsInventory568=== PAUSE TestMetricsInventory569=== RUN TestService_NativeMTLS570=== PAUSE TestService_NativeMTLS571=== RUN TestServerTLSConfig572=== PAUSE TestServerTLSConfig573=== RUN TestMultipartCleanup574=== PAUSE TestMultipartCleanup575=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded576=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded577=== RUN TestPendingCleanupUsesOneCutoff578=== PAUSE TestPendingCleanupUsesOneCutoff579=== RUN TestObjectStatsTrigger580=== PAUSE TestObjectStatsTrigger581=== RUN TestOrphanedObjectsGC582=== PAUSE TestOrphanedObjectsGC583=== RUN TestOrphanedObjectsGCStressTest584=== PAUSE TestOrphanedObjectsGCStressTest585=== RUN TestCreatePin_ReservedPins586=== PAUSE TestCreatePin_ReservedPins587=== RUN TestPresentReportsOnlyClosureRoots588=== PAUSE TestPresentReportsOnlyClosureRoots589=== RUN TestPresentNotReportedWhileGCDeletesClosure590=== PAUSE TestPresentNotReportedWhileGCDeletesClosure591=== RUN TestParseSingleRange592=== PAUSE TestParseSingleRange593=== RUN TestProxyHeadersOnlyTrustedOnSocket594=== PAUSE TestProxyHeadersOnlyTrustedOnSocket595=== RUN TestIsValidCachePath596=== PAUSE TestIsValidCachePath597=== RUN TestReadProxyNarinfo598=== PAUSE TestReadProxyNarinfo599=== RUN TestReadProxyNarinfoAlreadyDecompressed600=== PAUSE TestReadProxyNarinfoAlreadyDecompressed601=== RUN TestReadProxyNarStreaming602=== PAUSE TestReadProxyNarStreaming603=== RUN TestReadProxy404604=== PAUSE TestReadProxy404605=== RUN TestReadProxyInvalidPath606=== PAUSE TestReadProxyInvalidPath607=== RUN TestReadProxyHead608=== PAUSE TestReadProxyHead609=== RUN TestReadProxyOutlastsServerWriteTimeout610=== PAUSE TestReadProxyOutlastsServerWriteTimeout611=== RUN TestReadProxyConditionalGet612=== PAUSE TestReadProxyConditionalGet613=== RUN TestReadProxyRootRedirectsToIndexHTML614=== PAUSE TestReadProxyRootRedirectsToIndexHTML615=== RUN TestReadProxyDisabled616=== PAUSE TestReadProxyDisabled617=== RUN TestReadRedirectNar618=== PAUSE TestReadRedirectNar619=== RUN TestReadRedirectKeepsNarinfoProxied620=== PAUSE TestReadRedirectKeepsNarinfoProxied621=== RUN TestReadProxyRangeRequest622=== PAUSE TestReadProxyRangeRequest623=== RUN TestReadRedirectUsesPublicS3URL624=== PAUSE TestReadRedirectUsesPublicS3URL625=== RUN TestPush_OverlappingRootsStoreOneRowPerKey626=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey627=== RUN TestPush_CompleteCommitsEveryRoot628=== PAUSE TestPush_CompleteCommitsEveryRoot629=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit630=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit631=== RUN TestPush_RejectsBadRequests632=== PAUSE TestPush_RejectsBadRequests633=== RUN TestPush_SignsNarinfosOfItsPendingObjects634=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects635=== RUN TestRedundantMultipartUpload636=== PAUSE TestRedundantMultipartUpload637=== RUN TestCompleteMultipartUpload_ErrorButObjectExists638=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists639=== RUN TestCompletedNarNotReofferedAcrossClosures640=== PAUSE TestCompletedNarNotReofferedAcrossClosures641=== RUN TestPresignedUploadRegisteredBeforeCommit642=== PAUSE TestPresignedUploadRegisteredBeforeCommit643=== RUN TestService_Rustfstest644=== PAUSE TestService_Rustfstest645=== RUN TestParseSize646=== PAUSE TestParseSize647=== RUN TestSkippedUploadsHandler648=== PAUSE TestSkippedUploadsHandler649=== RUN TestSystemdListenerNotActivated650--- PASS: TestSystemdListenerNotActivated (0.00s)651=== RUN TestWatchdogBeatsWhenHealthy652--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)653=== RUN TestWatchdogSkipsWhenUnhealthy6542026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/04 20:06:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"664--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)665=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== RUN TestProxyWriteTimeout668=== PAUSE TestProxyWriteTimeout669=== RUN TestPendingClosureWriteTimeout670=== PAUSE TestPendingClosureWriteTimeout671=== RUN TestIsValidUploadKey672=== PAUSE TestIsValidUploadKey673=== RUN TestUploadHandlersRejectInvalidKeys674=== PAUSE TestUploadHandlersRejectInvalidKeys675=== RUN TestUploadHandlersRejectOversizedBody676=== PAUSE TestUploadHandlersRejectOversizedBody677=== RUN TestService_cleanupPendingClosuresHandler678=== PAUSE TestService_cleanupPendingClosuresHandler679=== RUN TestService_createPendingClosureHandler680=== PAUSE TestService_createPendingClosureHandler681=== RUN TestService_verifyS3Integrity682=== PAUSE TestService_verifyS3Integrity683=== RUN TestCompleteMultipartUnregistered684=== PAUSE TestCompleteMultipartUnregistered685=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT686=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT687=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle688=== CONT TestService_AuthMiddleware689=== CONT TestSkippedUploadsHandler690=== CONT TestParseSize691=== CONT TestService_Rustfstest692=== CONT TestPresignedUploadRegisteredBeforeCommit693=== CONT TestCompletedNarNotReofferedAcrossClosures6942026/10/04 20:06:51 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000695=== CONT TestCompleteMultipartUpload_ErrorButObjectExists696=== CONT TestRedundantMultipartUpload697=== CONT TestPush_SignsNarinfosOfItsPendingObjects698=== CONT TestPush_RejectsBadRequests699=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit700=== CONT TestPush_CompleteCommitsEveryRoot701=== CONT TestPush_OverlappingRootsStoreOneRowPerKey702=== CONT TestReadRedirectUsesPublicS3URL703=== CONT TestService_cleanupPendingClosuresHandler704=== CONT TestReadProxyRangeRequest705=== CONT TestReadRedirectKeepsNarinfoProxied706=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT707=== CONT TestReadRedirectNar708=== CONT TestCompleteMultipartUnregistered709=== CONT TestReadProxyDisabled710=== CONT TestService_verifyS3Integrity711=== CONT TestReadProxyRootRedirectsToIndexHTML712--- PASS: TestParseSize (0.00s)713=== CONT TestService_createPendingClosureHandler714--- PASS: TestSkippedUploadsHandler (0.00s)715=== CONT TestReadProxyConditionalGet7162026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures7172026/10/04 20:06:51 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7182026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures7192026/10/04 20:06:51 INFO Received push request method=POST path=/api/pushes720--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.31s)721=== CONT TestIsValidUploadKey722=== RUN TestIsValidUploadKey/narinfo723=== PAUSE TestIsValidUploadKey/narinfo724=== RUN TestIsValidUploadKey/nar_zst725=== PAUSE TestIsValidUploadKey/nar_zst726=== RUN TestIsValidUploadKey/nar_xz727=== PAUSE TestIsValidUploadKey/nar_xz728=== RUN TestIsValidUploadKey/nar_plain729=== PAUSE TestIsValidUploadKey/nar_plain730=== RUN TestIsValidUploadKey/listing731=== PAUSE TestIsValidUploadKey/listing732=== RUN TestIsValidUploadKey/build_log733=== PAUSE TestIsValidUploadKey/build_log734=== RUN TestIsValidUploadKey/build_log_home-manager_file735=== PAUSE TestIsValidUploadKey/build_log_home-manager_file736=== RUN TestIsValidUploadKey/build_log_plus_in_name737=== PAUSE TestIsValidUploadKey/build_log_plus_in_name738=== RUN TestIsValidUploadKey/build_log_question_mark739=== PAUSE TestIsValidUploadKey/build_log_question_mark740=== RUN TestIsValidUploadKey/build_log_equals741=== PAUSE TestIsValidUploadKey/build_log_equals742=== RUN TestIsValidUploadKey/realisation743=== PAUSE TestIsValidUploadKey/realisation744=== RUN TestIsValidUploadKey/realisation_plus_in_output745=== PAUSE TestIsValidUploadKey/realisation_plus_in_output746=== RUN TestIsValidUploadKey/nix-cache-info747=== PAUSE TestIsValidUploadKey/nix-cache-info748=== RUN TestIsValidUploadKey/index.html749=== PAUSE TestIsValidUploadKey/index.html750=== RUN TestIsValidUploadKey/narinfo_key,_nar_type751=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type752=== RUN TestIsValidUploadKey/nar_key,_narinfo_type753=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type754=== RUN TestIsValidUploadKey/listing_key,_narinfo_type755=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type756=== RUN TestIsValidUploadKey/traversal757=== PAUSE TestIsValidUploadKey/traversal758=== RUN TestIsValidUploadKey/traversal_nar759=== PAUSE TestIsValidUploadKey/traversal_nar760=== RUN TestIsValidUploadKey/absolute761=== PAUSE TestIsValidUploadKey/absolute762=== RUN TestIsValidUploadKey/empty_key763=== PAUSE TestIsValidUploadKey/empty_key764=== RUN TestIsValidUploadKey/unknown_type765=== PAUSE TestIsValidUploadKey/unknown_type766=== CONT TestReadProxyOutlastsServerWriteTimeout7672026/10/04 20:06:51 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"768--- PASS: TestService_AuthMiddleware (0.33s)769=== CONT TestUploadHandlersRejectOversizedBody7702026/10/04 20:06:51 INFO Received complete push request method=POST path=/api/pushes/1/complete7712026/10/04 20:06:51 INFO Received push request method=POST path=/api/pushes7722026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures773--- PASS: TestService_Rustfstest (0.36s)774=== CONT TestReadProxyHead775=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure776=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure777=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart778=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart779=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts780=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts781=== CONT TestUploadHandlersRejectInvalidKeys782=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info783=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info784=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal785=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal786=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key787=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key788=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key789=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key790=== CONT TestReadProxyInvalidPath7912026/10/04 20:06:51 INFO Aborted multipart uploads count=0 kept=07922026/10/04 20:06:51 WARN Force mode enabled - objects will be deleted immediately without grace period7932026/10/04 20:06:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7942026/10/04 20:06:51 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=07952026/10/04 20:06:51 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLjdhN2Q3MDlmLWQxZjMtNDA4OC04MTVkLTVmNThhN2ZlMzk4OHgxNzkxMTQ0NDExNzM4NDEzNTc17962026/10/04 20:06:51 INFO Vacuumed table table=pending_closures7972026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures7982026/10/04 20:06:51 INFO Vacuumed table table=pending_objects7992026/10/04 20:06:51 INFO Vacuumed table table=multipart_uploads8002026/10/04 20:06:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLjdhN2Q3MDlmLWQxZjMtNDA4OC04MTVkLTVmNThhN2ZlMzk4OHgxNzkxMTQ0NDExNzM4NDEzNTc1 parts=18012026/10/04 20:06:51 INFO Vacuumed table table=closures802--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.49s)803=== CONT TestPendingClosureWriteTimeout804=== RUN TestPendingClosureWriteTimeout/empty805=== PAUSE TestPendingClosureWriteTimeout/empty806=== RUN TestPendingClosureWriteTimeout/400_objects807=== PAUSE TestPendingClosureWriteTimeout/400_objects808=== RUN TestPendingClosureWriteTimeout/670k_objects809=== PAUSE TestPendingClosureWriteTimeout/670k_objects810=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline811=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline812=== CONT TestReadProxy4048132026/10/04 20:06:51 INFO Vacuumed table table=objects8142026/10/04 20:06:51 INFO Received complete push request method=POST path=/api/pushes/2/complete8152026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures816--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.49s)817=== CONT TestReadProxyNarStreaming8182026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures8192026/10/04 20:06:51 INFO Received push request method=POST path=/api/pushes8202026/10/04 20:06:51 INFO Received complete push request method=POST path=/api/pushes/1/complete8212026/10/04 20:06:51 INFO Received push request method=POST path=/api/pushes822--- PASS: TestPush_CompleteCommitsEveryRoot (0.55s)823=== CONT TestSweepRechecksPendingAfterLocking824--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.56s)825=== CONT TestGetExistingObjectsLocksRows8262026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures8272026/10/04 20:06:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete828=== RUN TestPush_RejectsBadRequests/no_roots829=== PAUSE TestPush_RejectsBadRequests/no_roots830=== RUN TestPush_RejectsBadRequests/no_objects831=== PAUSE TestPush_RejectsBadRequests/no_objects832=== RUN TestPush_RejectsBadRequests/bad_root833=== PAUSE TestPush_RejectsBadRequests/bad_root834=== RUN TestPush_RejectsBadRequests/root_not_in_objects835=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects836=== CONT TestReadProxyNarinfoAlreadyDecompressed837--- PASS: TestReadProxyDisabled (0.61s)838=== CONT TestRegisterCompletedObjectNeedsPendingRow8392026/10/04 20:06:52 INFO Received cleanup request method=DELETE path=/api/pending_closures8402026/10/04 20:06:52 INFO Aborted multipart uploads count=0 kept=08412026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures8422026/10/04 20:06:52 INFO Received cleanup request method=DELETE path=/api/pending_closures8432026/10/04 20:06:52 INFO Aborted multipart uploads count=1 kept=08442026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures8452026/10/04 20:06:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8462026-10-04 20:06:52.048 UTC [473] ERROR: Closure does not exist: id=18472026-10-04 20:06:52.048 UTC [473] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8482026-10-04 20:06:52.048 UTC [473] STATEMENT: -- name: CommitPendingClosure :exec849 SELECT commit_pending_closure($1::bigint)850 851--- PASS: TestService_cleanupPendingClosuresHandler (0.66s)852=== CONT TestReadProxyNarinfo853--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.66s)854=== CONT TestClientFallsBackToClosures855--- PASS: TestReadRedirectKeepsNarinfoProxied (0.69s)856=== CONT TestIsValidCachePath857=== RUN TestIsValidCachePath/narinfo858=== PAUSE TestIsValidCachePath/narinfo859=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars860=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars861=== RUN TestIsValidCachePath/nar_zst862=== PAUSE TestIsValidCachePath/nar_zst863=== RUN TestIsValidCachePath/nar_xz864=== PAUSE TestIsValidCachePath/nar_xz865=== RUN TestIsValidCachePath/nar_bz2866=== PAUSE TestIsValidCachePath/nar_bz2867=== RUN TestIsValidCachePath/nar_uncompressed868=== PAUSE TestIsValidCachePath/nar_uncompressed869=== RUN TestIsValidCachePath/ls870=== PAUSE TestIsValidCachePath/ls871=== RUN TestIsValidCachePath/log872=== PAUSE TestIsValidCachePath/log873=== RUN TestIsValidCachePath/realisation874=== PAUSE TestIsValidCachePath/realisation875=== RUN TestIsValidCachePath/nix-cache-info876=== PAUSE TestIsValidCachePath/nix-cache-info877=== RUN TestIsValidCachePath/index.html878=== PAUSE TestIsValidCachePath/index.html879=== RUN TestIsValidCachePath/traversal_parent880=== PAUSE TestIsValidCachePath/traversal_parent881=== RUN TestIsValidCachePath/traversal_in_middle882=== PAUSE TestIsValidCachePath/traversal_in_middle883=== RUN TestIsValidCachePath/invalid_char_e884=== PAUSE TestIsValidCachePath/invalid_char_e885=== RUN TestIsValidCachePath/invalid_char_u886=== PAUSE TestIsValidCachePath/invalid_char_u887=== RUN TestIsValidCachePath/random_path888=== PAUSE TestIsValidCachePath/random_path889=== RUN TestIsValidCachePath/empty890=== PAUSE TestIsValidCachePath/empty891=== RUN TestIsValidCachePath/leading_slash892=== PAUSE TestIsValidCachePath/leading_slash893=== RUN TestIsValidCachePath/wrong_extension894=== PAUSE TestIsValidCachePath/wrong_extension895=== RUN TestIsValidCachePath/short_hash896=== PAUSE TestIsValidCachePath/short_hash897=== CONT TestClientPushesUseOnePush898--- PASS: TestReadRedirectNar (0.71s)899=== CONT TestProxyHeadersOnlyTrustedOnSocket9002026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes9012026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9022026/10/04 20:06:52 INFO Signed narinfos id=1 count=1903--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.74s)904=== CONT TestPinProtectsFromGC905--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.74s)906=== CONT TestParseSingleRange907=== RUN TestParseSingleRange/none908=== PAUSE TestParseSingleRange/none909=== RUN TestParseSingleRange/unknown_unit910=== PAUSE TestParseSingleRange/unknown_unit911=== RUN TestParseSingleRange/multi-range_ignored912=== PAUSE TestParseSingleRange/multi-range_ignored913=== RUN TestParseSingleRange/malformed_no_dash914=== PAUSE TestParseSingleRange/malformed_no_dash915=== RUN TestParseSingleRange/malformed_both_empty916=== PAUSE TestParseSingleRange/malformed_both_empty917=== RUN TestParseSingleRange/malformed_end_before_start918=== PAUSE TestParseSingleRange/malformed_end_before_start919=== RUN TestParseSingleRange/closed920=== PAUSE TestParseSingleRange/closed921=== RUN TestParseSingleRange/open-ended922=== PAUSE TestParseSingleRange/open-ended923=== RUN TestParseSingleRange/end_clamped_to_size924=== PAUSE TestParseSingleRange/end_clamped_to_size925=== RUN TestParseSingleRange/suffix926=== PAUSE TestParseSingleRange/suffix927=== RUN TestParseSingleRange/suffix_exceeds_size928=== PAUSE TestParseSingleRange/suffix_exceeds_size929=== RUN TestParseSingleRange/single_byte930=== PAUSE TestParseSingleRange/single_byte931=== RUN TestParseSingleRange/start_past_EOF932=== PAUSE TestParseSingleRange/start_past_EOF933=== RUN TestParseSingleRange/start_far_past_EOF934=== PAUSE TestParseSingleRange/start_far_past_EOF935=== CONT TestClientSharedPathCommittedMidPush936--- PASS: TestReadProxyRangeRequest (0.77s)937=== CONT TestPresentNotReportedWhileGCDeletesClosure9382026/10/04 20:06:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9392026/10/04 20:06:52 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst940--- PASS: TestCompleteMultipartUnregistered (0.78s)941=== CONT TestClientWithDependencies9422026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures9432026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures9442026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures9452026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures946--- PASS: TestReadProxyConditionalGet (0.86s)947=== CONT TestPresentReportsOnlyClosureRoots9482026/10/04 20:06:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9492026/10/04 20:06:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLjJlYjkxYzhkLTQyMTYtNDdhMS1hMzU2LTBlODM4Y2VkNzMyN3gxNzkxMTQ0NDExODc2OTYzMjA0 parts=12950--- PASS: TestReadRedirectUsesPublicS3URL (0.89s)951=== CONT TestCreatePin_ReservedPins9522026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures954--- PASS: TestReadProxyHead (0.54s)955=== CONT TestClientMultipleUploads9562026/10/04 20:06:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete957--- PASS: TestReadProxyInvalidPath (0.47s)958=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9592026/10/04 20:06:52 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLmM4YmNkOTI5LWVkYzAtNDkwNS04YTFhLWM0ZjRjNmRkOWQ1NXgxNzkxMTQ0NDExOTU4MDkzOTQ0 parts=129602026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures961--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.95s)962=== CONT TestClientIntegration9632026/10/04 20:06:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39599/oidc964--- PASS: TestReadProxy404 (0.49s)965=== CONT TestOrphanedObjectsGCStressTest966--- PASS: TestReadProxyNarStreaming (0.49s)967=== CONT TestClientErrorHandling968=== RUN TestClientErrorHandling/InvalidStorePath969=== PAUSE TestClientErrorHandling/InvalidStorePath970=== RUN TestClientErrorHandling/InvalidAuthToken971=== PAUSE TestClientErrorHandling/InvalidAuthToken972=== RUN TestClientErrorHandling/ServerNotAvailable973=== PAUSE TestClientErrorHandling/ServerNotAvailable974=== CONT TestOrphanedObjectsGC975--- PASS: TestGetExistingObjectsLocksRows (0.46s)976=== CONT TestObjectStatsTrigger9772026/10/04 20:06:52 INFO Aborted multipart uploads count=0 kept=09782026/10/04 20:06:52 WARN Force mode enabled - objects will be deleted immediately without grace period979--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.47s)980=== CONT TestPendingCleanupUsesOneCutoff9812026/10/04 20:06:52 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=09822026/10/04 20:06:52 INFO Vacuumed table table=pending_closures9832026/10/04 20:06:52 INFO Vacuumed table table=pending_objects9842026/10/04 20:06:52 INFO Vacuumed table table=multipart_uploads9852026/10/04 20:06:52 INFO Vacuumed table table=closures9862026/10/04 20:06:52 INFO Vacuumed table table=objects987--- PASS: TestSweepRechecksPendingAfterLocking (0.53s)988=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded989--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.48s)990=== CONT TestMultipartCleanup9912026/10/04 20:06:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/10/04 20:06:52 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLjkzMjhmNGFiLWNjMDItNGEzMS1hM2JlLTA1ZTFlZTBkYjI2N3gxNzkxMTQ0NDEyMjA5MTk3OTky parts=109932026/10/04 20:06:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9942026/10/04 20:06:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9952026/10/04 20:06:52 INFO Completed upload id=19962026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures9972026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures9982026/10/04 20:06:52 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9992026/10/04 20:06:52 WARN Found objects in DB but missing from S3, will re-upload count=11000--- PASS: TestService_verifyS3Integrity (1.14s)1001=== CONT TestServerTLSConfig1002=== RUN TestServerTLSConfig/no_client_CA1003=== PAUSE TestServerTLSConfig/no_client_CA1004=== RUN TestServerTLSConfig/missing_CA_file1005=== PAUSE TestServerTLSConfig/missing_CA_file1006=== RUN TestServerTLSConfig/not_a_PEM_file1007=== PAUSE TestServerTLSConfig/not_a_PEM_file1008=== CONT TestService_NativeMTLS10092026/10/04 20:06:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLjg0ZTU2MmQyLTBiYzQtNGYzNi04ODFjLTAwYzJkNjJlOTgyNXgxNzkxMTQ0NDEyMjI0NzAyOTI5 parts=1010102026/10/04 20:06:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10112026/10/04 20:06:52 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10122026/10/04 20:06:52 INFO Completed upload id=110132026/10/04 20:06:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010142026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/04 20:06:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures10162026/10/04 20:06:52 INFO Aborted multipart uploads count=0 kept=010172026/10/04 20:06:52 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=010182026/10/04 20:06:52 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3423708939/001/proxy.sock10192026/10/04 20:06:52 INFO Starting HTTP server address=127.0.0.1:3807510202026/10/04 20:06:52 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10212026/10/04 20:06:52 INFO Shutdown signal received, draining in-flight requests timeout=10s1022--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.47s)1023=== CONT TestClientCADerivations10242026/10/04 20:06:52 INFO Vacuumed table table=pending_closures10252026/10/04 20:06:52 INFO Vacuumed table table=pending_objects10262026/10/04 20:06:52 INFO Vacuumed table table=multipart_uploads10272026/10/04 20:06:52 INFO Vacuumed table table=closures10282026/10/04 20:06:52 INFO Vacuumed table table=objects10292026/10/04 20:06:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001030--- PASS: TestService_createPendingClosureHandler (1.21s)1031=== CONT TestMetricsInventory10322026/10/04 20:06:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10332026/10/04 20:06:52 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLmJhMzE4YjNjLWM0ZTEtNDMzYy04NjQyLWE1NjU5MjcxOTQ2Y3gxNzkxMTQ0NDEyMjg4MjMyMTUz error="Get \"http://127.0.0.1:1/bucket8/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10342026/10/04 20:06:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MGVjY2YyOWItZjBkZC00MzZmLTkzYmYtYTgzOTE5ZTBjMDFkLjJjM2ZmYmY1LTk2OWYtNDBkMS1hZjQ0LWQzOWNmZjg3ZDgxZngxNzkxMTQ0NDEyMjgyMTU2Njc5 parts=121035=== NAME TestPinProtectsFromGC1036 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1662315303/001/store/79wn1jzb5m4f0nacvbzz1wpb45l7lx9k-pinned-file.txt1037 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1662315303/001/store/36m3xq3436454knw6lqhrb4qjb6sskli-unpinned-file.txt10382026/10/04 20:06:52 INFO Received cleanup request method=DELETE path=/api/pending_closures10392026/10/04 20:06:52 INFO Aborted multipart uploads count=1 kept=01040--- PASS: TestRedundantMultipartUpload (1.29s)1041=== CONT TestCacheStatsHandler10422026/10/04 20:06:52 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161043--- PASS: TestReadProxyNarinfo (0.64s)1044=== CONT TestNARDeduplicationMetadataUploadBug1045--- PASS: TestPresentReportsOnlyClosureRoots (0.45s)1046=== CONT TestCacheConfigHandler1047=== RUN TestCacheConfigHandler/full_config,_no_issuer1048=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1049=== RUN TestCacheConfigHandler/no_cache_url_configured1050=== PAUSE TestCacheConfigHandler/no_cache_url_configured1051=== RUN TestCacheConfigHandler/no_signing_keys1052=== PAUSE TestCacheConfigHandler/no_signing_keys1053=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1054=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1055=== CONT TestSweepSkipsRowsLockedByPush10562026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes10582026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures10592026/10/04 20:06:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10602026/10/04 20:06:52 INFO Uploading xxkl3kmj2dl4l9bcyb84mllxq8nlb352-shared-dep (136B)10612026/10/04 20:06:52 INFO Uploading fxmlsh2a6f2rr2xwmgzf3zkgiywnwh3q-a (216B)10622026/10/04 20:06:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10632026/10/04 20:06:52 INFO Uploading wf9634ycypj0dpd0jl132zjdmfnm8gz2-a (216B)10642026/10/04 20:06:52 INFO Uploading m6ik1rcrkb22963f673qjj6ssd6vipw9-shared-dep (136B)10652026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes10662026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/1amg33kidn53m7vv9s9z0x6k5yhs2l9fnzcg0sz8n6hac31b5pqj.nar.zst error="server returned 404: 404 page not found\n"10672026/10/04 20:06:52 WARN Failed to register uploaded object key=xxkl3kmj2dl4l9bcyb84mllxq8nlb352.ls error="server returned 404: 404 page not found\n"10682026/10/04 20:06:52 WARN Failed to register uploaded object key=fxmlsh2a6f2rr2xwmgzf3zkgiywnwh3q.ls error="server returned 404: 404 page not found\n"10692026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10702026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10712026/10/04 20:06:52 WARN Failed to register uploaded object key=54zqpah768gndyvhdr9lpfpbdndyc3ck.ls error="server returned 404: 404 page not found\n"10722026/10/04 20:06:52 INFO Signed narinfos id=1 count=310732026/10/04 20:06:52 WARN Failed to register uploaded object key=wf9634ycypj0dpd0jl132zjdmfnm8gz2.ls error="server returned 404: 404 page not found\n"10742026/10/04 20:06:52 INFO Uploading 3 narinfos10752026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10762026/10/04 20:06:52 WARN Failed to register uploaded object key=m6ik1rcrkb22963f673qjj6ssd6vipw9.ls error="server returned 404: 404 page not found\n"10772026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/1ccbnwv6rvjv8k1s445f4m52ddjp56474jmyy5qrqpfrkj30ndqm.nar.zst error="server returned 404: 404 page not found\n"10782026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10792026/10/04 20:06:52 WARN Failed to register uploaded object key=cyah83669v0g6jisal038ikaj5j4m7ii.ls error="server returned 404: 404 page not found\n"10802026/10/04 20:06:52 INFO Signed narinfos id=1 count=210812026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10822026/10/04 20:06:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10832026/10/04 20:06:52 INFO Uploading 79wn1jzb5m4f0nacvbzz1wpb45l7lx9k-pinned-file.txt (128B)10842026/10/04 20:06:52 INFO Signed narinfos id=2 count=210852026/10/04 20:06:52 INFO Uploading 4 narinfos10862026/10/04 20:06:52 WARN Failed to register uploaded object key=xxkl3kmj2dl4l9bcyb84mllxq8nlb352.narinfo error="server returned 404: 404 page not found\n"10872026/10/04 20:06:52 WARN Failed to register uploaded object key=54zqpah768gndyvhdr9lpfpbdndyc3ck.narinfo error="server returned 404: 404 page not found\n"10882026/10/04 20:06:52 INFO Received complete push request method=POST path=/api/pushes/1/complete10892026/10/04 20:06:52 WARN Failed to register uploaded object key=fxmlsh2a6f2rr2xwmgzf3zkgiywnwh3q.narinfo error="server returned 404: 404 page not found\n"10902026/10/04 20:06:52 WARN Failed to register uploaded object key=wf9634ycypj0dpd0jl132zjdmfnm8gz2.narinfo error="server returned 404: 404 page not found\n"10912026/10/04 20:06:52 WARN Failed to register uploaded object key=m6ik1rcrkb22963f673qjj6ssd6vipw9.narinfo error="server returned 404: 404 page not found\n"10922026/10/04 20:06:52 WARN Failed to register uploaded object key=cyah83669v0g6jisal038ikaj5j4m7ii.narinfo error="server returned 404: 404 page not found\n"10932026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10942026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10952026/10/04 20:06:52 WARN Failed to register uploaded object key=79wn1jzb5m4f0nacvbzz1wpb45l7lx9k.ls error="server returned 404: 404 page not found\n"10962026/10/04 20:06:52 INFO Signed narinfos id=1 count=110972026/10/04 20:06:52 INFO Uploading 1 narinfos10982026/10/04 20:06:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10992026/10/04 20:06:52 WARN Failed to register uploaded object key=m6ik1rcrkb22963f673qjj6ssd6vipw9.narinfo error="server returned 404: 404 page not found\n"11002026/10/04 20:06:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11012026/10/04 20:06:52 WARN Failed to register uploaded object key=79wn1jzb5m4f0nacvbzz1wpb45l7lx9k.narinfo error="server returned 404: 404 page not found\n"11022026/10/04 20:06:52 INFO Upload complete. (62ms)11032026/10/04 20:06:52 INFO Completed upload id=111042026/10/04 20:06:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1105=== NAME TestClientPushesUseOnePush1106 client_pushes_test.go:97: Retrieved narinfo from S3:1107 StorePath: /build/TestClientPushesUseOnePush3175410522/001/store/xxkl3kmj2dl4l9bcyb84mllxq8nlb352-shared-dep1108 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1109 Compression: zstd1110 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821111 NarSize: 1361112 References: 1113 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1114=== NAME TestClientMultipleUploads1115 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1982807911/001/store/c0a7ifk5r4nyxk955b0p90ndg0cpgbhi-test-file-0.txt11162026/10/04 20:06:52 INFO Completed upload id=211172026/10/04 20:06:52 INFO Upload complete. (68ms)11182026/10/04 20:06:52 INFO Upload complete. (58ms)1119=== NAME TestClientFallsBackToClosures1120 client_pushes_test.go:112: Retrieved narinfo from S3:1121 StorePath: /build/TestClientFallsBackToClosures2541865384/001/store/m6ik1rcrkb22963f673qjj6ssd6vipw9-shared-dep1122 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1123 Compression: zstd1124 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821125 NarSize: 1361126 References: 1127 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1128=== NAME TestClientWithDependencies1129 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3756747684/001/store/rl5vypzld0rndqh3m4xnm8n6mf67d3kc-test-script1130=== NAME TestClientPushesUseOnePush1131 client_pushes_test.go:97: Retrieved narinfo from S3:1132 StorePath: /build/TestClientPushesUseOnePush3175410522/001/store/fxmlsh2a6f2rr2xwmgzf3zkgiywnwh3q-a1133 URL: nar/1amg33kidn53m7vv9s9z0x6k5yhs2l9fnzcg0sz8n6hac31b5pqj.nar.zst1134 Compression: zstd1135 NarHash: sha256:1amg33kidn53m7vv9s9z0x6k5yhs2l9fnzcg0sz8n6hac31b5pqj1136 NarSize: 2161137 References: /build/TestClientPushesUseOnePush3175410522/001/store/xxkl3kmj2dl4l9bcyb84mllxq8nlb352-shared-dep1138 CA: text:sha256:0y2lfpgp6r157dbijwjl6n9bsdqm9ggpwk13iznrciz2jgnr8p8w1139=== NAME TestClientFallsBackToClosures1140 client_pushes_test.go:112: Retrieved narinfo from S3:1141 StorePath: /build/TestClientFallsBackToClosures2541865384/001/store/wf9634ycypj0dpd0jl132zjdmfnm8gz2-a1142 URL: nar/1ccbnwv6rvjv8k1s445f4m52ddjp56474jmyy5qrqpfrkj30ndqm.nar.zst1143 Compression: zstd1144 NarHash: sha256:1ccbnwv6rvjv8k1s445f4m52ddjp56474jmyy5qrqpfrkj30ndqm1145 NarSize: 2161146 References: /build/TestClientFallsBackToClosures2541865384/001/store/m6ik1rcrkb22963f673qjj6ssd6vipw9-shared-dep1147 CA: text:sha256:0hkpc9zv7x6b2jsysq2h93rq51slilfgr6m4c4nbxawdhs5426gn1148=== NAME TestClientPushesUseOnePush1149 client_pushes_test.go:97: Retrieved narinfo from S3:1150 StorePath: /build/TestClientPushesUseOnePush3175410522/001/store/54zqpah768gndyvhdr9lpfpbdndyc3ck-b1151 URL: nar/1amg33kidn53m7vv9s9z0x6k5yhs2l9fnzcg0sz8n6hac31b5pqj.nar.zst1152 Compression: zstd1153 NarHash: sha256:1amg33kidn53m7vv9s9z0x6k5yhs2l9fnzcg0sz8n6hac31b5pqj1154 NarSize: 2161155 References: /build/TestClientPushesUseOnePush3175410522/001/store/xxkl3kmj2dl4l9bcyb84mllxq8nlb352-shared-dep1156 CA: text:sha256:0y2lfpgp6r157dbijwjl6n9bsdqm9ggpwk13iznrciz2jgnr8p8w1157=== NAME TestClientFallsBackToClosures1158 client_pushes_test.go:112: Retrieved narinfo from S3:1159 StorePath: /build/TestClientFallsBackToClosures2541865384/001/store/cyah83669v0g6jisal038ikaj5j4m7ii-b1160 URL: nar/1ccbnwv6rvjv8k1s445f4m52ddjp56474jmyy5qrqpfrkj30ndqm.nar.zst1161 Compression: zstd1162 NarHash: sha256:1ccbnwv6rvjv8k1s445f4m52ddjp56474jmyy5qrqpfrkj30ndqm1163 NarSize: 2161164 References: /build/TestClientFallsBackToClosures2541865384/001/store/m6ik1rcrkb22963f673qjj6ssd6vipw9-shared-dep1165 CA: text:sha256:0hkpc9zv7x6b2jsysq2h93rq51slilfgr6m4c4nbxawdhs5426gn1166--- PASS: TestClientPushesUseOnePush (0.68s)1167=== CONT TestService_ReadScope_PublicByDefault1168--- PASS: TestClientFallsBackToClosures (0.71s)1169=== CONT TestCreatePendingClosureRejectsOversizedNAR11702026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures1171--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1172=== CONT TestFailedS3DeleteKeepsTombstone11732026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes11742026/10/04 20:06:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11752026/10/04 20:06:52 WARN Refused reserved pin name=worker-x86_64-linux11762026/10/04 20:06:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11772026/10/04 20:06:52 INFO Received create pin request method=POST path=/api/pins/my-app11782026/10/04 20:06:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1179--- PASS: TestCreatePin_ReservedPins (0.50s)1180=== CONT TestService_RequireScope_OIDC11812026/10/04 20:06:52 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11822026/10/04 20:06:52 INFO Uploading f03x0clkgfs2i7k1jq7ysdpd2iczi6cs-top (224B)11832026/10/04 20:06:52 INFO Uploading 2j2iknlb2yw622qaw6sabvxp7k4lhkvy-shared-dep (136B)1184=== NAME TestClientWithDependencies1185 client_integration_test.go:615: Found 1 dependencies (including self)1186=== NAME TestClientMultipleUploads1187 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1982807911/001/store/w7w9kjqny3s4rhpsfvd880nggp317ydy-test-file-1.txt11882026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11892026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11902026/10/04 20:06:52 WARN Failed to register uploaded object key=2j2iknlb2yw622qaw6sabvxp7k4lhkvy.ls error="server returned 404: 404 page not found\n"11912026/10/04 20:06:52 WARN Failed to register uploaded object key=f03x0clkgfs2i7k1jq7ysdpd2iczi6cs.ls error="server returned 404: 404 page not found\n"11922026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/0zg5d4f79152la7v3a2kafbs0p9lwzkh94q1kxycs6x98dh11k83.nar.zst error="server returned 404: 404 page not found\n"11932026/10/04 20:06:52 INFO Signed narinfos id=1 count=211942026/10/04 20:06:52 INFO Uploading 2 narinfos1195=== NAME TestClientIntegration1196 client_integration_test.go:286: Created store path: /build/TestClientIntegration358816444/002/store/4ybfpbg3lfyi9714jfykgri3j5k67lis-test-file.txt11972026/10/04 20:06:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11982026/10/04 20:06:52 WARN Failed to register uploaded object key=2j2iknlb2yw622qaw6sabvxp7k4lhkvy.narinfo error="server returned 404: 404 page not found\n"11992026/10/04 20:06:52 WARN Failed to register uploaded object key=f03x0clkgfs2i7k1jq7ysdpd2iczi6cs.narinfo error="server returned 404: 404 page not found\n"12002026/10/04 20:06:52 INFO Upload complete. (60ms)1201=== NAME TestClientSharedPathCommittedMidPush1202 client_integration_test.go:680: Retrieved narinfo from S3:1203 StorePath: /build/TestClientSharedPathCommittedMidPush4228019634/001/store/2j2iknlb2yw622qaw6sabvxp7k4lhkvy-shared-dep1204 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1205 Compression: zstd1206 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821207 NarSize: 1361208 References: 1209 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1210 client_integration_test.go:680: Retrieved narinfo from S3:1211 StorePath: /build/TestClientSharedPathCommittedMidPush4228019634/001/store/f03x0clkgfs2i7k1jq7ysdpd2iczi6cs-top1212 URL: nar/0zg5d4f79152la7v3a2kafbs0p9lwzkh94q1kxycs6x98dh11k83.nar.zst1213 Compression: zstd1214 NarHash: sha256:0zg5d4f79152la7v3a2kafbs0p9lwzkh94q1kxycs6x98dh11k831215 NarSize: 2241216 References: /build/TestClientSharedPathCommittedMidPush4228019634/001/store/2j2iknlb2yw622qaw6sabvxp7k4lhkvy-shared-dep1217 CA: text:sha256:0s482fj70asn2i5ppl6l331fkk2gjnzw5fgg2mm9dwy1dppfh0w61218--- PASS: TestClientSharedPathCommittedMidPush (0.68s)1219=== CONT TestForceGCDuringPushOffersSweptObject1220=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1221=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1222=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1223=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1224=== CONT TestGCTaskStore_GetReturnsLatest1225--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1226=== CONT TestService_AuthMiddleware_OIDC12272026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes12282026/10/04 20:06:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12292026/10/04 20:06:52 INFO Uploading 36m3xq3436454knw6lqhrb4qjb6sskli-unpinned-file.txt (128B)1230=== NAME TestClientMultipleUploads1231 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1982807911/001/store/8lkqnf8przr493jmn9vsmg4qslhp2170-test-file-2.txt12322026/10/04 20:06:52 WARN Failed to register uploaded object key=36m3xq3436454knw6lqhrb4qjb6sskli.ls error="server returned 404: 404 page not found\n"12332026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12342026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12352026/10/04 20:06:52 INFO Signed narinfos id=2 count=112362026/10/04 20:06:52 INFO Uploading 1 narinfos12372026/10/04 20:06:52 INFO Received complete push request method=POST path=/api/pushes/2/complete12382026/10/04 20:06:52 WARN Failed to register uploaded object key=36m3xq3436454knw6lqhrb4qjb6sskli.narinfo error="server returned 404: 404 page not found\n"12392026/10/04 20:06:52 INFO Upload complete. (46ms)1240--- PASS: TestObjectStatsTrigger (0.44s)1241=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12422026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes12442026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes12452026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures12462026/10/04 20:06:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12472026/10/04 20:06:52 INFO Uploading rl5vypzld0rndqh3m4xnm8n6mf67d3kc-test-script (136B)12482026/10/04 20:06:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12492026/10/04 20:06:52 INFO Uploading 4ybfpbg3lfyi9714jfykgri3j5k67lis-test-file.txt (152B)12502026/10/04 20:06:52 WARN Failed to register uploaded object key=rl5vypzld0rndqh3m4xnm8n6mf67d3kc.ls error="server returned 404: 404 page not found\n"12512026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12522026/10/04 20:06:52 WARN Failed to register uploaded object key=4ybfpbg3lfyi9714jfykgri3j5k67lis.ls error="server returned 404: 404 page not found\n"12532026/10/04 20:06:52 WARN Failed to register uploaded object key=log/2n8vb0qg5j0wj41lr5k3jixxpbhhz0ix-test-script.drv error="server returned 404: 404 page not found\n"12542026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12552026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12562026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12572026/10/04 20:06:52 INFO Signed narinfos id=1 count=112582026/10/04 20:06:52 INFO Signed narinfos id=1 count=112592026/10/04 20:06:52 INFO Uploading 1 narinfos12602026/10/04 20:06:52 INFO Uploading 1 narinfos12612026/10/04 20:06:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures12622026/10/04 20:06:52 INFO Garbage collection started12632026/10/04 20:06:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12642026/10/04 20:06:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12652026/10/04 20:06:52 WARN Failed to register uploaded object key=4ybfpbg3lfyi9714jfykgri3j5k67lis.narinfo error="server returned 404: 404 page not found\n"12662026/10/04 20:06:52 WARN Failed to register uploaded object key=rl5vypzld0rndqh3m4xnm8n6mf67d3kc.narinfo error="server returned 404: 404 page not found\n"12672026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures12682026/10/04 20:06:52 INFO Received cleanup request method=DELETE path=/api/pending_closures12692026/10/04 20:06:52 INFO Upload complete. (53ms)12702026/10/04 20:06:52 INFO Upload complete. (58ms)1271=== NAME TestClientWithDependencies1272 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3756747684/001/store) requires matching store prefix12732026/10/04 20:06:52 INFO Aborted multipart uploads count=0 kept=01274--- PASS: TestClientWithDependencies (0.71s)1275=== CONT TestGCTaskStore_GetEmpty1276--- PASS: TestGCTaskStore_GetEmpty (0.00s)1277=== CONT TestService_ReadAuthMiddleware12782026/10/04 20:06:52 WARN Force mode enabled - objects will be deleted immediately without grace period1279--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.41s)1280=== CONT TestGCSweepDeliversEachKeyOnce12812026/10/04 20:06:52 INFO Received uploads request method=POST path=/api/pending_closures12822026/10/04 20:06:52 INFO Received push request method=POST path=/api/pushes12832026/10/04 20:06:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42519/oidc12842026/10/04 20:06:52 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=012852026/10/04 20:06:52 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12862026/10/04 20:06:52 INFO Uploading c0a7ifk5r4nyxk955b0p90ndg0cpgbhi-test-file-0.txt (160B)12872026/10/04 20:06:52 INFO Uploading w7w9kjqny3s4rhpsfvd880nggp317ydy-test-file-1.txt (160B)12882026/10/04 20:06:52 INFO Uploading 8lkqnf8przr493jmn9vsmg4qslhp2170-test-file-2.txt (160B)12892026/10/04 20:06:52 INFO Vacuumed table table=pending_closures12902026/10/04 20:06:52 WARN Failed to register uploaded object key=c0a7ifk5r4nyxk955b0p90ndg0cpgbhi.ls error="server returned 404: 404 page not found\n"12912026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12922026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12932026/10/04 20:06:52 WARN Failed to register uploaded object key=w7w9kjqny3s4rhpsfvd880nggp317ydy.ls error="server returned 404: 404 page not found\n"12942026/10/04 20:06:52 INFO Vacuumed table table=pending_objects12952026/10/04 20:06:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12962026/10/04 20:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12972026/10/04 20:06:52 WARN Failed to register uploaded object key=8lkqnf8przr493jmn9vsmg4qslhp2170.ls error="server returned 404: 404 page not found\n"12982026/10/04 20:06:52 INFO Vacuumed table table=multipart_uploads12992026/10/04 20:06:52 INFO Signed narinfos id=1 count=313002026/10/04 20:06:52 INFO Uploading 3 narinfos13012026/10/04 20:06:52 INFO Vacuumed table table=closures13022026/10/04 20:06:52 WARN Failed to register uploaded object key=8lkqnf8przr493jmn9vsmg4qslhp2170.narinfo error="server returned 404: 404 page not found\n"13032026/10/04 20:06:52 WARN Failed to register uploaded object key=c0a7ifk5r4nyxk955b0p90ndg0cpgbhi.narinfo error="server returned 404: 404 page not found\n"13042026/10/04 20:06:52 INFO Received complete push request method=POST path=/api/pushes/1/complete13052026/10/04 20:06:52 WARN Failed to register uploaded object key=w7w9kjqny3s4rhpsfvd880nggp317ydy.narinfo error="server returned 404: 404 page not found\n"13062026/10/04 20:06:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13072026/10/04 20:06:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13082026/10/04 20:06:52 INFO Vacuumed table table=objects1309--- PASS: TestService_NativeMTLS (0.37s)1310=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13112026/10/04 20:06:52 INFO All 1 paths already cached1312=== NAME TestClientIntegration1313 client_integration_test.go:312: Retrieved narinfo from S3:1314 StorePath: /build/TestClientIntegration358816444/002/store/4ybfpbg3lfyi9714jfykgri3j5k67lis-test-file.txt1315 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1316 Compression: zstd1317 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11318 NarSize: 1521319 References: 1320 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11321 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1322 client_integration_test.go:313: Decompressed .ls content (64 bytes):1323 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1324 client_integration_test.go:316: Testing garbage collection...13252026/10/04 20:06:52 INFO Upload complete. (61ms)1326=== NAME TestClientMultipleUploads1327 client_integration_test.go:369: Uploaded 3 paths in 93.127946ms1328--- PASS: TestClientMultipleUploads (0.63s)1329=== CONT TestGCTaskStore_ConflictDifferentParams1330--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1331=== CONT TestService_AuthMiddleware_MTLSProxyHeader13322026/10/04 20:06:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36341/oidc13332026/10/04 20:06:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures13342026/10/04 20:06:52 INFO Garbage collection started13352026/10/04 20:06:52 INFO Aborted multipart uploads count=0 kept=013362026/10/04 20:06:52 WARN Force mode enabled - objects will be deleted immediately without grace period1337--- PASS: TestMetricsInventory (0.37s)1338=== CONT TestTombstonedObjectOfferedWithoutWaiting13392026/10/04 20:06:52 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=01340--- PASS: TestCacheStatsHandler (0.31s)1341=== CONT TestGCTaskStore_DeduplicateSameParams1342--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1343=== CONT TestGCSweepSkipsPendingObjects13442026/10/04 20:06:52 INFO Vacuumed table table=pending_closures13452026/10/04 20:06:52 INFO Vacuumed table table=pending_objects13462026/10/04 20:06:52 INFO Vacuumed table table=multipart_uploads13472026/10/04 20:06:52 INFO Vacuumed table table=closures13482026/10/04 20:06:53 INFO Received cleanup request method=DELETE path=/api/pending_closures13492026/10/04 20:06:53 INFO Vacuumed table table=objects13502026/10/04 20:06:53 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket54/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13512026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=113522026/10/04 20:06:53 INFO Received cleanup request method=DELETE path=/api/pending_closures13532026/10/04 20:06:53 INFO Aborted multipart uploads count=1 kept=013542026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=013552026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period1356--- PASS: TestMultipartCleanup (0.54s)1357=== CONT TestGCTaskStore_StartNew1358--- PASS: TestGCTaskStore_StartNew (0.00s)1359=== CONT TestService_healthCheckHandler13602026/10/04 20:06:53 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=013612026/10/04 20:06:53 INFO Vacuumed table table=pending_closures13622026/10/04 20:06:53 INFO Vacuumed table table=pending_objects13632026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads13642026/10/04 20:06:53 INFO Vacuumed table table=closures13652026/10/04 20:06:53 INFO Vacuumed table table=objects1366=== NAME TestClientCADerivations1367 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1212875417/001/store/gcan928d7ap9r5hlhimk1j68zzv69ffh-ca-test13682026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=013692026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period13702026/10/04 20:06:53 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=013712026/10/04 20:06:53 INFO Vacuumed table table=pending_closures13722026/10/04 20:06:53 INFO Vacuumed table table=pending_objects13732026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads13742026/10/04 20:06:53 INFO Vacuumed table table=closures1375--- PASS: TestService_ReadScope_PublicByDefault (0.27s)1376=== CONT TestDeduplicatedObjectsRecordedAsPending13772026/10/04 20:06:53 INFO Vacuumed table table=objects1378--- PASS: TestSweepSkipsRowsLockedByPush (0.34s)1379=== CONT TestGCEndsOnShutdown1380=== RUN TestGCEndsOnShutdown/before_the_run1381=== PAUSE TestGCEndsOnShutdown/before_the_run1382=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1383=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1384=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1385=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1386=== CONT TestCacheConfigHandlerMaxNarSize1387--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1388=== CONT TestCommitRacingPendingCleanupKeepsObjects1389=== NAME TestClientCADerivations1390 client_ca_test.go:139: Found 1 dependencies (including self)1391=== NAME TestNARDeduplicationMetadataUploadBug1392 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1238625285/001/store/l7x9gi4zx1nflxzi0gqh1rsfhh8x9fr5-file1.txt13932026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures13942026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures1395--- PASS: TestService_ReadAuthMiddleware (0.23s)1396=== CONT TestGCTaskStore_CompletedAllowsNewTask1397--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1398=== CONT TestPushWaitsForSweepHoldingRow13992026/10/04 20:06:53 INFO Received push request method=POST path=/api/pushes1400=== NAME TestOrphanedObjectsGC1401 orphaned_objects_gc_test.go:290: GC Test Summary:1402 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1403 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1404 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1405 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1406 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1407--- PASS: TestOrphanedObjectsGC (0.76s)1408=== CONT TestPushDedupSurvivesConcurrentGC14092026/10/04 20:06:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14102026/10/04 20:06:53 INFO Uploading l7x9gi4zx1nflxzi0gqh1rsfhh8x9fr5-file1.txt (160B)14112026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=014122026/10/04 20:06:53 WARN Failed to register uploaded object key=l7x9gi4zx1nflxzi0gqh1rsfhh8x9fr5.ls error="server returned 404: 404 page not found\n"14132026/10/04 20:06:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14142026/10/04 20:06:53 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14152026/10/04 20:06:53 INFO Signed narinfos id=1 count=114162026/10/04 20:06:53 INFO Uploading 1 narinfos14172026/10/04 20:06:53 INFO Received complete push request method=POST path=/api/pushes/1/complete14182026/10/04 20:06:53 WARN Failed to register uploaded object key=l7x9gi4zx1nflxzi0gqh1rsfhh8x9fr5.narinfo error="server returned 404: 404 page not found\n"14192026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period1420--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.83s)1421=== CONT TestGracefulShutdownDrainsInflight14222026/10/04 20:06:53 INFO Starting HTTP server address=127.0.0.1:4473514232026/10/04 20:06:53 INFO Shutdown signal received, draining in-flight requests timeout=10s14242026/10/04 20:06:53 INFO Upload complete. (66ms)1425=== NAME TestNARDeduplicationMetadataUploadBug1426 metadata_upload_test.go:54: Retrieved narinfo from S3:1427 StorePath: /build/TestNARDeduplicationMetadataUploadBug1238625285/001/store/l7x9gi4zx1nflxzi0gqh1rsfhh8x9fr5-file1.txt1428 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1429 Compression: zstd1430 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1431 NarSize: 1601432 References: 1433 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1434 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1435 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1436 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1437--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.00s)1438=== CONT TestProxyWriteTimeout1439=== RUN TestProxyWriteTimeout/narinfo1440=== PAUSE TestProxyWriteTimeout/narinfo1441=== RUN TestProxyWriteTimeout/1_GiB_nar1442=== PAUSE TestProxyWriteTimeout/1_GiB_nar1443=== RUN TestProxyWriteTimeout/10_GiB_nar1444=== PAUSE TestProxyWriteTimeout/10_GiB_nar1445=== RUN TestProxyWriteTimeout/unknown_size1446=== PAUSE TestProxyWriteTimeout/unknown_size14472026/10/04 20:06:53 INFO Received push request method=POST path=/api/pushes1448=== CONT TestGCTaskStore_Fail1449--- PASS: TestGCTaskStore_Fail (0.00s)1450=== CONT TestService_readinessHandler14512026/10/04 20:06:53 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14522026/10/04 20:06:53 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1453--- PASS: TestFailedS3DeleteKeepsTombstone (0.40s)1454=== CONT TestGCTaskStore_PhaseUpdates1455--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1456=== CONT TestLeadEndsOnShutdown14572026/10/04 20:06:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14582026/10/04 20:06:53 INFO Uploading gcan928d7ap9r5hlhimk1j68zzv69ffh-ca-test (144B)14592026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=014602026/10/04 20:06:53 WARN Failed to register uploaded object key=log/yqp26c59sr9cprbwrcgzv470hs9w2wkp-ca-test.drv error="server returned 404: 404 page not found\n"14612026/10/04 20:06:53 WARN Failed to register uploaded object key=gcan928d7ap9r5hlhimk1j68zzv69ffh.ls error="server returned 404: 404 page not found\n"14622026/10/04 20:06:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14632026/10/04 20:06:53 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14642026/10/04 20:06:53 INFO Signed narinfos id=1 count=114652026/10/04 20:06:53 INFO Uploading 1 narinfos1466=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1467=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1468=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1469=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1470=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1471=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1472=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1473=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1474=== CONT TestGCBugBareHashReferences14752026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period14762026/10/04 20:06:53 INFO Received complete push request method=POST path=/api/pushes/1/complete14772026/10/04 20:06:53 WARN Failed to register uploaded object key=gcan928d7ap9r5hlhimk1j68zzv69ffh.narinfo error="server returned 404: 404 page not found\n"14782026/10/04 20:06:53 INFO Upload complete. (104ms)14792026/10/04 20:06:53 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=01480=== NAME TestNARDeduplicationMetadataUploadBug1481 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1238625285/001/store/hb1pf2jcbazrf919s8j7gr4sa9ci36ih-file2.txt14822026/10/04 20:06:53 INFO Vacuumed table table=pending_closures14832026/10/04 20:06:53 INFO Vacuumed table table=pending_objects1484=== NAME TestClientCADerivations1485 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1212875417/001/store/gcan928d7ap9r5hlhimk1j68zzv69ffh-ca-test1486 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1487 Compression: zstd1488 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1489 NarSize: 1441490 References: 1491 Deriver: /build/TestClientCADerivations1212875417/001/store/yqp26c59sr9cprbwrcgzv470hs9w2wkp-ca-test.drv1492 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1493 client_ca_test.go:185: Checking for realisation files in S3...14942026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads14952026/10/04 20:06:53 INFO Vacuumed table table=closures1496 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1497 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14982026/10/04 20:06:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14992026/10/04 20:06:53 WARN mTLS auth: bound subjects configured but subject DN unavailable15002026/10/04 20:06:53 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1501--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.29s)1502=== CONT TestGCAdvisoryLockBlocksConcurrentRun15032026/10/04 20:06:53 INFO Vacuumed table table=objects1504--- PASS: TestGCSweepDeliversEachKeyOnce (0.32s)1505=== CONT TestGCMetrics1506--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1507=== CONT TestConnectWaitsForAPeerMigration1508--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.30s)1509=== CONT TestLeadElectsOneAndHandsOver15102026/10/04 20:06:53 INFO Received push request method=POST path=/api/pushes1511=== RUN TestService_RequireScope_OIDC/builder_may_write1512=== PAUSE TestService_RequireScope_OIDC/builder_may_write1513=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1514=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1515=== RUN TestService_RequireScope_OIDC/ops_may_admin1516=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1517=== RUN TestService_RequireScope_OIDC/ops_may_not_write1518=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1519=== RUN TestService_RequireScope_OIDC/reader_may_not_write1520=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1521=== RUN TestService_RequireScope_OIDC/static_token_may_admin1522=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1523=== RUN TestService_RequireScope_OIDC/static_token_may_write1524=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1525=== RUN TestService_RequireScope_OIDC/reader_may_read1526=== PAUSE TestService_RequireScope_OIDC/reader_may_read1527=== RUN TestService_RequireScope_OIDC/writer_implies_read1528=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1529=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1530=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1531=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1532=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1533=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1534=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1535=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1536=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1537=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1538=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1539=== CONT TestResolveDBConnectionString1540=== RUN TestResolveDBConnectionString/flag_wins1541=== PAUSE TestResolveDBConnectionString/flag_wins1542=== RUN TestResolveDBConnectionString/file_when_flag_empty1543=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1544=== RUN TestResolveDBConnectionString/missing_file_is_an_error1545=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1546=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1547=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1548=== RUN TestResolveDBConnectionString/nothing_configured1549=== PAUSE TestResolveDBConnectionString/nothing_configured1550=== CONT TestGenerateLandingPage15512026/10/04 20:06:53 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1552--- PASS: TestGenerateLandingPage (0.00s)1553=== CONT TestIsValidUploadKey/narinfo1554=== CONT TestIsValidUploadKey/realisation_plus_in_output1555=== CONT TestIsValidUploadKey/unknown_type1556=== CONT TestIsValidUploadKey/empty_key1557=== CONT TestIsValidUploadKey/absolute1558=== CONT TestIsValidUploadKey/traversal_nar1559=== CONT TestIsValidUploadKey/traversal1560=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1561=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1562=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1563=== CONT TestIsValidUploadKey/index.html1564=== CONT TestIsValidUploadKey/nix-cache-info1565=== CONT TestIsValidUploadKey/build_log_home-manager_file1566=== CONT TestIsValidUploadKey/build_log_equals1567=== CONT TestIsValidUploadKey/build_log_question_mark1568=== CONT TestIsValidUploadKey/realisation1569=== CONT TestIsValidUploadKey/build_log_plus_in_name1570=== CONT TestIsValidUploadKey/build_log1571=== CONT TestIsValidUploadKey/listing1572=== CONT TestIsValidUploadKey/nar_xz1573=== CONT TestIsValidUploadKey/nar_plain1574=== CONT TestIsValidUploadKey/nar_zst1575--- PASS: TestIsValidUploadKey (0.00s)1576 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1577 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1578 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1579 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1580 --- PASS: TestIsValidUploadKey/absolute (0.00s)1581 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1582 --- PASS: TestIsValidUploadKey/traversal (0.00s)1583 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1584 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1585 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1586 --- PASS: TestIsValidUploadKey/index.html (0.00s)1587 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1588 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1589 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1590 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1591 --- PASS: TestIsValidUploadKey/realisation (0.00s)1592 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1593 --- PASS: TestIsValidUploadKey/build_log (0.00s)1594 --- PASS: TestIsValidUploadKey/listing (0.00s)1595 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1596 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1597 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1598=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15992026/10/04 20:06:53 INFO Received uploads request method=POST path=/16002026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures16012026/10/04 20:06:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16022026/10/04 20:06:53 INFO Signed narinfos id=2 count=116032026/10/04 20:06:53 WARN Failed to register uploaded object key=hb1pf2jcbazrf919s8j7gr4sa9ci36ih.ls error="server returned 404: 404 page not found\n"16042026/10/04 20:06:53 INFO Uploading 1 narinfos1605--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.31s)1606=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16072026/10/04 20:06:53 INFO Received request for more parts method=POST path=/16082026/10/04 20:06:53 INFO Received complete push request method=POST path=/api/pushes/2/complete16092026/10/04 20:06:53 WARN Failed to register uploaded object key=hb1pf2jcbazrf919s8j7gr4sa9ci36ih.narinfo error="server returned 404: 404 page not found\n"16102026/10/04 20:06:53 INFO Upload complete. (52ms)1611=== NAME TestNARDeduplicationMetadataUploadBug1612 metadata_upload_test.go:76: Retrieved narinfo from S3:1613 StorePath: /build/TestNARDeduplicationMetadataUploadBug1238625285/001/store/hb1pf2jcbazrf919s8j7gr4sa9ci36ih-file2.txt1614 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1615 Compression: zstd1616 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1617 NarSize: 1601618 References: 1619 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1620 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1621 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1622 {"version":1,"root":{"type":"regular","size":44}}1623--- PASS: TestNARDeduplicationMetadataUploadBug (0.60s)1624=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16252026/10/04 20:06:53 INFO Received complete multipart upload request method=POST path=/1626=== NAME TestClientCADerivations1627 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1628 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1629 error: binary cache 's3://bucket56?endpoint=http://localhost:42395®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1212875417/001/store'16302026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures1631 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11632--- PASS: TestClientCADerivations (0.73s)1633=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16342026/10/04 20:06:53 INFO Received uploads request method=POST path=/1635=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16362026/10/04 20:06:53 INFO Received complete multipart upload request method=POST path=/1637=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16382026/10/04 20:06:53 INFO Received uploads request method=POST path=/1639=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16402026/10/04 20:06:53 INFO Received request for more parts method=POST path=/1641--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1642 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (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 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1646=== CONT TestPendingClosureWriteTimeout/empty1647=== CONT TestPendingClosureWriteTimeout/670k_objects1648=== CONT TestPendingClosureWriteTimeout/400_objects1649=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1650--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.46s)1651=== CONT TestPush_RejectsBadRequests/no_roots16522026/10/04 20:06:53 INFO Received push request method=POST path=/api/pushes1653=== CONT TestPush_RejectsBadRequests/bad_root16542026/10/04 20:06:53 INFO Received push request method=POST path=/api/pushes1655=== CONT TestPush_RejectsBadRequests/root_not_in_objects16562026/10/04 20:06:53 INFO Received push request method=POST path=/api/pushes1657=== CONT TestPush_RejectsBadRequests/no_objects16582026/10/04 20:06:53 INFO Received push request method=POST path=/api/pushes1659=== CONT TestIsValidCachePath/narinfo1660--- PASS: TestPush_RejectsBadRequests (0.59s)1661 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1662 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1663 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1664 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1665=== CONT TestIsValidCachePath/short_hash1666=== CONT TestIsValidCachePath/wrong_extension1667=== CONT TestIsValidCachePath/leading_slash1668=== CONT TestIsValidCachePath/empty1669=== CONT TestIsValidCachePath/random_path1670=== CONT TestIsValidCachePath/invalid_char_u1671=== CONT TestIsValidCachePath/invalid_char_e1672=== CONT TestIsValidCachePath/traversal_in_middle1673=== CONT TestIsValidCachePath/traversal_parent1674=== CONT TestIsValidCachePath/index.html1675=== CONT TestIsValidCachePath/nix-cache-info1676=== CONT TestIsValidCachePath/realisation1677=== CONT TestIsValidCachePath/log1678=== CONT TestIsValidCachePath/ls1679=== CONT TestIsValidCachePath/nar_uncompressed1680=== CONT TestIsValidCachePath/nar_bz21681=== CONT TestIsValidCachePath/nar_xz1682=== CONT TestIsValidCachePath/nar_zst1683=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1684=== CONT TestParseSingleRange/none1685=== CONT TestParseSingleRange/open-ended1686=== CONT TestParseSingleRange/start_far_past_EOF1687=== CONT TestParseSingleRange/start_past_EOF1688=== CONT TestParseSingleRange/single_byte1689=== CONT TestParseSingleRange/suffix_exceeds_size1690=== CONT TestParseSingleRange/suffix1691=== CONT TestParseSingleRange/end_clamped_to_size1692=== CONT TestParseSingleRange/closed1693=== CONT TestParseSingleRange/malformed_end_before_start1694=== CONT TestParseSingleRange/malformed_both_empty1695=== CONT TestParseSingleRange/multi-range_ignored1696--- PASS: TestIsValidCachePath (0.00s)1697 --- PASS: TestIsValidCachePath/narinfo (0.00s)1698 --- PASS: TestIsValidCachePath/short_hash (0.00s)1699 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1700 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1701 --- PASS: TestIsValidCachePath/empty (0.00s)1702 --- PASS: TestIsValidCachePath/random_path (0.00s)1703 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1704 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1705 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1706 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1707 --- PASS: TestIsValidCachePath/index.html (0.00s)1708 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1709 --- PASS: TestIsValidCachePath/realisation (0.00s)1710 --- PASS: TestIsValidCachePath/log (0.00s)1711 --- PASS: TestIsValidCachePath/ls (0.00s)1712 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1713 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1714 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1715 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1716 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1717=== CONT TestParseSingleRange/unknown_unit1718=== CONT TestParseSingleRange/malformed_no_dash1719=== CONT TestClientErrorHandling/InvalidStorePath1720--- PASS: TestParseSingleRange (0.00s)1721 --- PASS: TestParseSingleRange/none (0.00s)1722 --- PASS: TestParseSingleRange/open-ended (0.00s)1723 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1724 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1725 --- PASS: TestParseSingleRange/single_byte (0.00s)1726 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1727 --- PASS: TestParseSingleRange/suffix (0.00s)1728 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1729 --- PASS: TestParseSingleRange/closed (0.00s)1730 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1731 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1732 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1733 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1734 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1735--- PASS: TestService_healthCheckHandler (0.30s)1736=== CONT TestClientErrorHandling/ServerNotAvailable17372026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=017382026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period17392026/10/04 20:06:53 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=017402026/10/04 20:06:53 INFO Vacuumed table table=pending_closures17412026/10/04 20:06:53 INFO Vacuumed table table=pending_objects17422026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads17432026/10/04 20:06:53 INFO Vacuumed table table=closures17442026/10/04 20:06:53 INFO Vacuumed table table=objects17452026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures1746--- PASS: TestGCSweepSkipsPendingObjects (0.36s)1747=== CONT TestClientErrorHandling/InvalidAuthToken1748--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.30s)1749=== CONT TestServerTLSConfig/no_client_CA1750=== CONT TestServerTLSConfig/not_a_PEM_file1751=== CONT TestServerTLSConfig/missing_CA_file1752--- PASS: TestServerTLSConfig (0.00s)1753 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1754 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1755 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1756=== CONT TestCacheConfigHandler/full_config,_no_issuer1757=== CONT TestCacheConfigHandler/no_signing_keys1758=== CONT TestCacheConfigHandler/no_cache_url_configured1759=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1760--- PASS: TestCacheConfigHandler (0.00s)1761 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1762 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1763 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1764 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1765=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1766=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1767=== CONT TestGCEndsOnShutdown/before_the_run17682026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures17692026/10/04 20:06:53 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/present17702026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=017712026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period17722026/10/04 20:06:53 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=017732026/10/04 20:06:53 INFO Vacuumed table table=pending_closures17742026/10/04 20:06:53 INFO Vacuumed table table=pending_objects17752026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads17762026/10/04 20:06:53 INFO Vacuumed table table=closures17772026/10/04 20:06:53 INFO Vacuumed table table=objects17782026/10/04 20:06:53 INFO lead: acquired remote=192.0.2.1:123417792026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures1780--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.37s)1781=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17822026/10/04 20:06:53 WARN readiness check failed error="closed pool"1783--- PASS: TestService_readinessHandler (0.27s)1784=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17852026/10/04 20:06:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.446594ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17862026/10/04 20:06:53 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"1787--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.28s)1788=== CONT TestProxyWriteTimeout/narinfo1789=== CONT TestProxyWriteTimeout/10_GiB_nar1790=== CONT TestProxyWriteTimeout/unknown_size1791=== CONT TestProxyWriteTimeout/1_GiB_nar1792--- PASS: TestProxyWriteTimeout (0.00s)1793 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1794 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1795 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1796 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1797=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17982026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=01799=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1800=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18012026/10/04 20:06:53 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]1802=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18032026/10/04 20:06:53 WARN Authentication failed token_preview=eyJhbGciOi...hzFRUWUKPw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1804=== CONT TestService_RequireScope_OIDC/builder_may_write1805--- PASS: TestService_AuthMiddleware_OIDC (0.37s)1806 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1807 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1808 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1809 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1810=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc18112026/10/04 20:06:53 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=01812=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1813=== CONT TestService_RequireScope_OIDC/writer_implies_read1814=== CONT TestService_RequireScope_OIDC/reader_may_read1815=== CONT TestService_RequireScope_OIDC/static_token_may_write1816=== CONT TestService_RequireScope_OIDC/static_token_may_admin1817=== CONT TestService_RequireScope_OIDC/reader_may_not_write1818=== CONT TestService_RequireScope_OIDC/ops_may_not_write1819=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1820=== CONT TestService_RequireScope_OIDC/ops_may_admin1821=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1822=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1823=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18242026/10/04 20:06:53 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]1825=== CONT TestResolveDBConnectionString/flag_wins1826=== CONT TestResolveDBConnectionString/nothing_configured1827=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1828=== CONT TestResolveDBConnectionString/missing_file_is_an_error1829=== CONT TestResolveDBConnectionString/file_when_flag_empty1830--- PASS: TestService_RequireScope_OIDC (0.49s)1831 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1842 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1843 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1844 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1845--- PASS: TestResolveDBConnectionString (0.00s)1846 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1847 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1848 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1849 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1850 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18512026/10/04 20:06:53 INFO Vacuumed table table=pending_closures18522026/10/04 20:06:53 INFO Vacuumed table table=pending_objects18532026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads18542026/10/04 20:06:53 INFO Vacuumed table table=closures18552026/10/04 20:06:53 INFO Vacuumed table table=objects18562026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=018572026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=018582026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period18592026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period18602026/10/04 20:06:53 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=018612026/10/04 20:06:53 INFO Vacuumed table table=pending_closures18622026/10/04 20:06:53 INFO Vacuumed table table=pending_objects18632026/10/04 20:06:53 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=018642026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads18652026/10/04 20:06:53 INFO Vacuumed table table=closures18662026/10/04 20:06:53 INFO Vacuumed table table=pending_closures18672026/10/04 20:06:53 INFO Vacuumed table table=objects18682026/10/04 20:06:53 INFO Vacuumed table table=pending_objects18692026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads18702026/10/04 20:06:53 INFO Vacuumed table table=closures18712026/10/04 20:06:53 INFO Vacuumed table table=objects1872--- PASS: TestPushDedupSurvivesConcurrentGC (0.38s)18732026/10/04 20:06:53 INFO lead: acquired remote=192.0.2.1:12341874--- PASS: TestGCMetrics (0.31s)18752026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures18762026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures18772026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=018782026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period18792026/10/04 20:06:53 INFO Received uploads request method=POST path=/api/pending_closures18802026/10/04 20:06:53 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=018812026/10/04 20:06:53 INFO Vacuumed table table=pending_closures18822026/10/04 20:06:53 INFO Vacuumed table table=pending_objects18832026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads18842026/10/04 20:06:53 INFO Vacuumed table table=closures18852026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=018862026/10/04 20:06:53 INFO Vacuumed table table=objects18872026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period18882026/10/04 20:06:53 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=018892026/10/04 20:06:53 INFO Vacuumed table table=pending_closures18902026/10/04 20:06:53 INFO Vacuumed table table=pending_objects18912026/10/04 20:06:53 INFO Vacuumed table table=multipart_uploads18922026/10/04 20:06:53 INFO Vacuumed table table=closures18932026/10/04 20:06:53 INFO Vacuumed table table=objects1894--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1895 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)1896 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.30s)18972026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=018982026/10/04 20:06:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.147137ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18992026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period1900--- PASS: TestGCBugBareHashReferences (0.51s)19012026-10-04 20:06:53.683 UTC [1766] ERROR: canceling statement due to user request19022026-10-04 20:06:53.683 UTC [1766] CONTEXT: PL/pgSQL expression "(TG_OP = 'INSERT' OR TG_OP = 'UPDATE') AND NEW.deleted_at IS NULL"1903 PL/pgSQL function object_stats_apply() line 6 at IF19042026-10-04 20:06:53.683 UTC [1766] STATEMENT: -- name: MarkStaleObjects :execrows1905 WITH RECURSIVE ct AS (1906 SELECT timezone('UTC', now()) AS now1907 ),1908 closure_reach AS (1909 -- Start with all closure keys1910 SELECT o.key, o.refs1911 FROM objects o1912 INNER JOIN closures c ON o.key = c.key1913 UNION1914 -- Recursively add all referenced objects1915 SELECT o.key, o.refs1916 FROM objects o1917 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1918 ),1919 reachable_objects AS (1920 SELECT DISTINCT key FROM closure_reach1921 ),1922 stale_objects AS (1923 SELECT o.key1924 FROM objects AS o, ct1925 WHERE1926 NOT EXISTS (1927 SELECT 11928 FROM reachable_objects ro1929 WHERE ro.key = o.key1930 )1931 AND NOT EXISTS (1932 SELECT 11933 FROM pending_objects AS po1934 WHERE po.key = o.key1935 )1936 AND o.deleted_at IS NULL -- Only mark fresh objects1937 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1938 FOR UPDATE1939 )1940 UPDATE objects1941 SET1942 deleted_at = ct.now,1943 first_deleted_at = COALESCE(first_deleted_at, ct.now)1944 FROM stale_objects, ct1945 WHERE objects.key = stale_objects.key1946 19472026/10/04 20:06:53 INFO Aborted multipart uploads count=0 kept=019482026/10/04 20:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period19492026/10/04 20:06:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:42395/bucket90/?delete=\": context canceled"1950--- PASS: TestGCEndsOnShutdown (0.00s)1951 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)1952 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.27s)1953 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.26s)19542026/10/04 20:06:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19552026/10/04 20:06:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1956--- PASS: TestPushWaitsForSweepHoldingRow (0.77s)1957=== NAME TestOrphanedObjectsGCStressTest1958 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1959 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19602026/10/04 20:06:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=795.018085ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1961 orphaned_objects_gc_test.go:509: Stress test completed successfully:1962 orphaned_objects_gc_test.go:510: - Active objects preserved: 201963 orphaned_objects_gc_test.go:511: - Objects deleted: 2101964 orphaned_objects_gc_test.go:512: - Total GC'd: 2101965--- PASS: TestOrphanedObjectsGCStressTest (1.92s)1966--- PASS: TestPendingClosureWriteTimeout (0.00s)1967 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1968 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1969 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1970 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.07s)1971--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1972 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1973 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1974 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.11s)19752026/10/04 20:06:54 INFO lead: released remote=192.0.2.1:12341976--- PASS: TestLeadEndsOnShutdown (1.30s)19772026/10/04 20:06:54 INFO lead: released remote=192.0.2.1:123419782026/10/04 20:06:54 INFO lead: acquired remote=192.0.2.1:123419792026/10/04 20:06:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019802026/10/04 20:06:54 INFO Received create pin request method=POST path=/api/pins/myapp19812026/10/04 20:06:54 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1662315303/001/store/79wn1jzb5m4f0nacvbzz1wpb45l7lx9k-pinned-file.txt narinfo_key=79wn1jzb5m4f0nacvbzz1wpb45l7lx9k.narinfo19822026/10/04 20:06:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures19832026/10/04 20:06:54 INFO Garbage collection started19842026/10/04 20:06:54 INFO Aborted multipart uploads count=0 kept=019852026/10/04 20:06:54 WARN Force mode enabled - objects will be deleted immediately without grace period19862026/10/04 20:06:54 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=019872026/10/04 20:06:54 INFO Vacuumed table table=pending_closures19882026/10/04 20:06:54 INFO Vacuumed table table=pending_objects19892026/10/04 20:06:54 INFO Vacuumed table table=multipart_uploads19902026/10/04 20:06:54 INFO Vacuumed table table=closures19912026/10/04 20:06:54 INFO Vacuumed table table=objects19922026/10/04 20:06:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.443283683s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19932026/10/04 20:06:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01994=== NAME TestClientIntegration1995 client_integration_test.go:323: Objects in database after GC:1996 client_integration_test.go:323: Successfully deleted all objects with GC --force1997--- PASS: TestClientIntegration (2.62s)19982026/10/04 20:06:55 INFO lead: released remote=192.0.2.1:12341999--- PASS: TestLeadElectsOneAndHandsOver (2.64s)20002026/10/04 20:06:56 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-config20012026/10/04 20:06:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.816614ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2002--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.82s)20032026/10/04 20:06:56 WARN Rate limiter enabled after throttle name=s3-test rate=520042026/10/04 20:06:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2005=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2006 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102007 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002008--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.21s)20092026/10/04 20:06:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.505988ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2010=== NAME TestPinProtectsFromGC2011 client_integration_test.go:840: Pin successfully protected closure from garbage collection2012--- PASS: TestPinProtectsFromGC (4.76s)20132026/10/04 20:06:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=741.203465ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20142026/10/04 20:06:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.484659295s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2015--- PASS: TestConnectWaitsForAPeerMigration (5.14s)20162026/10/04 20:06:58 INFO Aborted multipart uploads count=1 kept=020172026/10/04 20:06:58 INFO Received cleanup request method=DELETE path=/api/pending_closures20182026/10/04 20:06:58 INFO Aborted multipart uploads count=1 kept=02019--- PASS: TestPendingCleanupUsesOneCutoff (6.44s)20202026/10/04 20:06:59 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"20212026/10/04 20:06:59 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-config20222026/10/04 20:06:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=211.294742ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20232026/10/04 20:06:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.21443ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20242026/10/04 20:07:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=853.465283ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20252026/10/04 20:07:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.70984789s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/04 20:07:02 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_closures20272026/10/04 20:07:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.063346ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20282026/10/04 20:07:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.055648ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20292026/10/04 20:07:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=867.89857ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20302026/10/04 20:07:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.508465043s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2031--- PASS: TestClientErrorHandling (0.00s)2032 --- PASS: TestClientErrorHandling/InvalidStorePath (0.31s)2033 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.40s)2034 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.42s)2035PASS20362026-10-04 20:07:05.978 UTC [128] LOG: received smart shutdown request20372026-10-04 20:07:05.983 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120382026-10-04 20:07:05.994 UTC [133] LOG: shutting down20392026-10-04 20:07:05.994 UTC [133] LOG: checkpoint starting: shutdown immediate20402026-10-04 20:07:06.860 UTC [133] LOG: checkpoint complete: wrote 10876 buffers (66.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.181 s, sync=0.656 s, total=0.867 s; sync files=30664, longest=0.002 s, average=0.001 s; distance=423884 kB, estimate=423884 kB; lsn=0/1B558FB0, redo lsn=0/1B558FB020412026-10-04 20:07:06.936 UTC [128] LOG: database system is shut down2042Running OIDC tests...2043=== RUN TestAudienceForIssuer2044=== PAUSE TestAudienceForIssuer2045=== RUN TestGlobMatch2046=== PAUSE TestGlobMatch2047=== RUN TestValidateToken_ValidToken2048=== PAUSE TestValidateToken_ValidToken2049=== RUN TestValidateToken_WrongAudience2050=== PAUSE TestValidateToken_WrongAudience2051=== RUN TestValidateToken_Expired2052=== PAUSE TestValidateToken_Expired2053=== RUN TestValidateToken_BoundClaimsMismatch2054=== PAUSE TestValidateToken_BoundClaimsMismatch2055=== RUN TestValidateToken_BoundSubjectMismatch2056=== PAUSE TestValidateToken_BoundSubjectMismatch2057=== RUN TestValidateToken_MultipleProviders2058=== PAUSE TestValidateToken_MultipleProviders2059=== RUN TestValidateToken_NoMatchingProvider2060=== PAUSE TestValidateToken_NoMatchingProvider2061=== RUN TestValidateToken_KubernetesServiceAccount2062=== PAUSE TestValidateToken_KubernetesServiceAccount2063=== RUN TestNewValidator_KubernetesRequiresCA2064=== PAUSE TestNewValidator_KubernetesRequiresCA2065=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2066=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2067=== RUN TestPins_ReservedForMatchingRule2068=== PAUSE TestPins_ReservedForMatchingRule2069=== RUN TestPins_TopLevelShorthand2070=== PAUSE TestPins_TopLevelShorthand2071=== RUN TestPins_ConfigValidation2072=== PAUSE TestPins_ConfigValidation2073=== RUN TestScopes_LegacyProviderDefaultsToWrite2074=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2075=== RUN TestScopes_Rules2076=== PAUSE TestScopes_Rules2077=== RUN TestScopes_ConfigValidation2078=== PAUSE TestScopes_ConfigValidation2079=== CONT TestAudienceForIssuer2080=== CONT TestValidateToken_BoundClaimsMismatch2081--- PASS: TestAudienceForIssuer (0.00s)2082=== CONT TestValidateToken_KubernetesServiceAccount2083=== CONT TestValidateToken_WrongAudience2084=== CONT TestScopes_ConfigValidation2085=== CONT TestScopes_Rules2086=== CONT TestScopes_LegacyProviderDefaultsToWrite2087--- PASS: TestScopes_ConfigValidation (0.00s)2088=== CONT TestPins_ConfigValidation2089=== CONT TestPins_TopLevelShorthand2090--- PASS: TestPins_ConfigValidation (0.00s)2091=== CONT TestPins_ReservedForMatchingRule2092=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2093=== CONT TestNewValidator_KubernetesRequiresCA2094=== CONT TestValidateToken_Expired2095=== CONT TestValidateToken_ValidToken2096=== CONT TestGlobMatch2097=== RUN TestGlobMatch/foo_foo2098=== PAUSE TestGlobMatch/foo_foo2099=== RUN TestGlobMatch/foo_bar2100=== PAUSE TestGlobMatch/foo_bar2101=== RUN TestGlobMatch/*_2102=== PAUSE TestGlobMatch/*_2103=== RUN TestGlobMatch/*_anything2104=== PAUSE TestGlobMatch/*_anything2105=== RUN TestGlobMatch/foo*_foo2106=== PAUSE TestGlobMatch/foo*_foo2107=== RUN TestGlobMatch/foo*_foobar2108=== PAUSE TestGlobMatch/foo*_foobar2109=== RUN TestGlobMatch/foo*_bar2110=== PAUSE TestGlobMatch/foo*_bar2111=== RUN TestGlobMatch/*bar_bar2112=== PAUSE TestGlobMatch/*bar_bar2113=== RUN TestGlobMatch/*bar_foobar2114=== PAUSE TestGlobMatch/*bar_foobar2115=== RUN TestGlobMatch/*bar_foo2116=== PAUSE TestGlobMatch/*bar_foo2117=== RUN TestGlobMatch/foo*bar_foobar2118=== PAUSE TestGlobMatch/foo*bar_foobar2119=== RUN TestGlobMatch/foo*bar_foo123bar2120=== PAUSE TestGlobMatch/foo*bar_foo123bar2121=== RUN TestGlobMatch/foo*bar_foobarbaz2122=== PAUSE TestGlobMatch/foo*bar_foobarbaz2123=== RUN TestGlobMatch/*/*_foo/bar2124=== PAUSE TestGlobMatch/*/*_foo/bar2125=== RUN TestGlobMatch/*/*_foo2126=== PAUSE TestGlobMatch/*/*_foo2127=== CONT TestValidateToken_MultipleProviders2128=== CONT TestValidateToken_NoMatchingProvider2129=== CONT TestValidateToken_BoundSubjectMismatch2130=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2131=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2132=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02133=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02134=== RUN TestGlobMatch/refs/*/main_refs/heads/main2135=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2136=== RUN TestGlobMatch/fo?_foo2137=== PAUSE TestGlobMatch/fo?_foo2138=== RUN TestGlobMatch/fo?_fo2139=== PAUSE TestGlobMatch/fo?_fo2140=== RUN TestGlobMatch/fo?_fooo2141=== PAUSE TestGlobMatch/fo?_fooo2142=== RUN TestGlobMatch/?oo_foo2143=== PAUSE TestGlobMatch/?oo_foo2144=== RUN TestGlobMatch/?oo_boo2145=== PAUSE TestGlobMatch/?oo_boo2146=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2147=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2148=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2149=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2150=== CONT TestGlobMatch/foo_foo2151=== CONT TestGlobMatch/?oo_foo2152=== CONT TestGlobMatch/fo?_fooo2153=== CONT TestGlobMatch/fo?_fo2154=== CONT TestGlobMatch/fo?_foo2155=== CONT TestGlobMatch/refs/*/main_refs/heads/main2156=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02157=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2158=== CONT TestGlobMatch/*/*_foo2159=== CONT TestGlobMatch/*/*_foo/bar2160=== CONT TestGlobMatch/foo*bar_foobarbaz2161=== CONT TestGlobMatch/?oo_boo2162=== CONT TestGlobMatch/*_2163=== CONT TestGlobMatch/foo_bar2164=== CONT TestGlobMatch/foo*bar_foo123bar2165=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2166=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2167=== 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--- PASS: TestGlobMatch (0.00s)2176 --- PASS: TestGlobMatch/foo_foo (0.00s)2177 --- PASS: TestGlobMatch/?oo_foo (0.00s)2178 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2179 --- PASS: TestGlobMatch/fo?_fo (0.00s)2180 --- PASS: TestGlobMatch/fo?_foo (0.00s)2181 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2182 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2183 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2184 --- PASS: TestGlobMatch/*/*_foo (0.00s)2185 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2186 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2187 --- PASS: TestGlobMatch/?oo_boo (0.00s)2188 --- PASS: TestGlobMatch/*_ (0.00s)2189 --- PASS: TestGlobMatch/foo_bar (0.00s)2190 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2191 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2192 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (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)22012026/10/04 20:07:08 http: TLS handshake error from 127.0.0.1:60086: remote error: tls: bad certificate2202--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)22032026/10/04 20:07:08 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232204--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)22052026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40389/oidc22062026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34959/oidc2207--- PASS: TestValidateToken_ValidToken (0.07s)2208--- PASS: TestScopes_Rules (0.07s)22092026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39689/oidc2210--- PASS: TestPins_ReservedForMatchingRule (0.10s)22112026/10/04 20:07:08 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41847/oidc22122026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39829/oidc2213--- PASS: TestValidateToken_NoMatchingProvider (0.10s)2214--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)22152026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34699/oidc2216--- PASS: TestValidateToken_Expired (0.11s)22172026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44653/oidc2218--- PASS: TestValidateToken_WrongAudience (0.12s)22192026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43499/oidc2220--- PASS: TestPins_TopLevelShorthand (0.14s)22212026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42687/oidc2222--- PASS: TestValidateToken_BoundClaimsMismatch (0.20s)22232026/10/04 20:07:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43005/oidc2224--- PASS: TestValidateToken_BoundSubjectMismatch (0.36s)22252026/10/04 20:07:08 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:349832226--- PASS: TestValidateToken_KubernetesServiceAccount (0.44s)22272026/10/04 20:07:08 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43759/oidc22282026/10/04 20:07:08 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40555/oidc2229--- PASS: TestValidateToken_MultipleProviders (0.45s)2230PASS2231Running hook tests...2232=== RUN TestSendPathsEmpty2233=== PAUSE TestSendPathsEmpty2234=== RUN TestQueueEnqueueAndFetch2235=== PAUSE TestQueueEnqueueAndFetch2236=== RUN TestQueueDeduplication2237=== PAUSE TestQueueDeduplication2238=== RUN TestQueueRemove2239=== PAUSE TestQueueRemove2240=== RUN TestQueueFetchBatchLimit2241=== PAUSE TestQueueFetchBatchLimit2242=== RUN TestQueueRetryMovesToBack2243=== PAUSE TestQueueRetryMovesToBack2244=== RUN TestQueueFetchRemoveLifecycle2245=== PAUSE TestQueueFetchRemoveLifecycle2246=== RUN TestQueueConcurrentWriters2247=== PAUSE TestQueueConcurrentWriters2248=== RUN TestQueueRemoveLargeClosure2249=== PAUSE TestQueueRemoveLargeClosure2250=== RUN TestServerClientIntegration2251=== PAUSE TestServerClientIntegration2252=== RUN TestServerQueueError2253=== PAUSE TestServerQueueError2254=== RUN TestGetListenerSocketActivation2255 server_test.go:210: === RUN TestGetListenerSocketActivation2256 --- PASS: TestGetListenerSocketActivation (0.00s)2257 PASS2258 2259--- PASS: TestGetListenerSocketActivation (0.01s)2260=== RUN TestDrainIsolatesPoisonPath2261=== PAUSE TestDrainIsolatesPoisonPath2262=== RUN TestRunNotBlockedByPoisonHead2263=== PAUSE TestRunNotBlockedByPoisonHead2264=== RUN TestDrainGivesUpWhenServerDown2265=== PAUSE TestDrainGivesUpWhenServerDown2266=== RUN TestFailedPathPrunedByLaterClosure2267=== PAUSE TestFailedPathPrunedByLaterClosure2268=== RUN TestWorkerUploadsAndRemoves2269=== PAUSE TestWorkerUploadsAndRemoves2270=== RUN TestWorkerSkipsGCdPaths2271=== PAUSE TestWorkerSkipsGCdPaths2272=== RUN TestWorkerPrunesClosureDeps2273=== PAUSE TestWorkerPrunesClosureDeps2274=== RUN TestDrainTimeout2275=== PAUSE TestDrainTimeout2276=== CONT TestSendPathsEmpty2277=== CONT TestFailedPathPrunedByLaterClosure2278=== CONT TestQueueConcurrentWriters2279--- PASS: TestSendPathsEmpty (0.00s)2280=== CONT TestQueueRetryMovesToBack2281=== CONT TestQueueFetchBatchLimit2282=== CONT TestQueueRemove2283=== CONT TestQueueDeduplication2284=== CONT TestQueueEnqueueAndFetch2285=== CONT TestDrainIsolatesPoisonPath2286=== CONT TestDrainGivesUpWhenServerDown2287=== CONT TestRunNotBlockedByPoisonHead2288=== CONT TestWorkerSkipsGCdPaths2289=== CONT TestWorkerUploadsAndRemoves2290=== CONT TestDrainTimeout2291=== CONT TestServerClientIntegration2292=== CONT TestServerQueueError2293=== CONT TestQueueRemoveLargeClosure2294=== CONT TestWorkerPrunesClosureDeps2295=== CONT TestQueueFetchRemoveLifecycle22962026/10/04 20:07:08 ERROR Failed to queue paths error="permission denied" count=12297--- PASS: TestServerClientIntegration (0.00s)2298--- PASS: TestServerQueueError (0.00s)22992026/10/04 20:07:08 INFO Uploading batch count=123002026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123012026/10/04 20:07:08 INFO Upload queue status pending=223022026/10/04 20:07:08 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3053458299/002/nonexistent23032026/10/04 20:07:08 INFO Upload queue status pending=323042026/10/04 20:07:08 INFO Upload queue status pending=223052026/10/04 20:07:08 INFO Uploading batch count=223062026/10/04 20:07:08 INFO Uploading batch count=123072026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123082026/10/04 20:07:08 INFO Uploading batch count=223092026/10/04 20:07:08 INFO Uploading batch count=123102026/10/04 20:07:08 INFO Uploading batch count=123112026/10/04 20:07:08 INFO Uploading batch count=423122026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=42313--- PASS: TestQueueEnqueueAndFetch (0.01s)2314--- PASS: TestQueueFetchBatchLimit (0.01s)23152026/10/04 20:07:08 INFO Uploading batch count=223162026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=223172026/10/04 20:07:08 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4050649265/002/a2318--- PASS: TestQueueRetryMovesToBack (0.02s)23192026/10/04 20:07:08 INFO Uploading batch count=12320--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23212026/10/04 20:07:08 INFO Upload queue status pending=223222026/10/04 20:07:08 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1211981077/002/bbb23232026/10/04 20:07:08 INFO Uploading batch count=12324--- PASS: TestQueueRemove (0.02s)23252026/10/04 20:07:08 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4050649265/002/b23262026/10/04 20:07:08 INFO Uploading batch count=223272026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=223282026/10/04 20:07:08 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4050649265/002/c2329--- PASS: TestQueueDeduplication (0.02s)23302026/10/04 20:07:08 INFO Uploading batch count=123312026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123322026/10/04 20:07:08 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4050649265/002/d23332026/10/04 20:07:08 INFO Uploading batch count=123342026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123352026/10/04 20:07:08 INFO Uploading batch count=22336--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23372026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=223382026/10/04 20:07:08 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4050649265/002/e23392026/10/04 20:07:08 INFO Uploading batch count=123402026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123412026/10/04 20:07:08 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4050649265/002/f23422026/10/04 20:07:08 ERROR Drain finished with paths left in queue remaining=123432026/10/04 20:07:08 ERROR Drain finished with paths left in queue remaining=102344--- PASS: TestDrainIsolatesPoisonPath (0.02s)2345--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2346--- PASS: TestWorkerSkipsGCdPaths (0.03s)2347--- PASS: TestWorkerPrunesClosureDeps (0.03s)2348--- PASS: TestWorkerUploadsAndRemoves (0.03s)2349--- PASS: TestQueueConcurrentWriters (0.13s)2350--- PASS: TestQueueRemoveLargeClosure (0.14s)23512026/10/04 20:07:09 ERROR Upload failed error="context deadline exceeded" count=223522026/10/04 20:07:09 ERROR Drain finished with paths left in queue remaining=42353--- PASS: TestDrainTimeout (0.21s)23542026/10/04 20:07:09 INFO Uploading batch count=123552026/10/04 20:07:09 INFO Uploading batch count=123562026/10/04 20:07:09 INFO Uploading batch count=123572026/10/04 20:07:09 ERROR Upload failed error="upload failed" count=123582026/10/04 20:07:09 INFO Uploading batch count=123592026/10/04 20:07:09 ERROR Upload failed error="upload failed" count=123602026/10/04 20:07:09 INFO Uploading batch count=123612026/10/04 20:07:09 ERROR Upload failed error="upload failed" count=123622026/10/04 20:07:09 INFO Uploading batch count=123632026/10/04 20:07:09 ERROR Upload failed error="upload failed" count=123642026/10/04 20:07:09 ERROR Drain finished with paths left in queue remaining=12365--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2366PASS