niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #352
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestDoWithRetry_BodyReplayedViaGetBody98=== CONT TestSetClientTLS99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestRateLimiterFeedback102=== CONT TestClientSignaturesByStorePath103--- PASS: TestClientSignaturesByStorePath (0.00s)104=== CONT TestScriptTokenNoExpiryRerunsEveryCall105=== CONT TestStreamPushIsolatesFailures106=== CONT TestStreamPushBatchesUnderLoad107=== CONT TestStreamPushReportsSignatures108=== CONT TestStreamPushReportsEveryPath109=== CONT TestStreamPushRequestLine110=== CONT TestShellSplitErrors111=== CONT TestParsePathInfoJSON112=== RUN TestParsePathInfoJSON/Nix_format113=== CONT TestStreamPushGivesUpOnDeadServer114=== CONT TestShellSplit115=== CONT TestSetClientTLSDoesNotMutateDefaultTransport116=== CONT TestFileTokenEmpty117=== CONT TestEncodeNixBase32WithRealHash118=== CONT TestScriptTokenBadJSON119=== CONT TestStaticToken120=== CONT TestResolveStorePath121=== CONT TestScriptTokenEmptyToken122=== CONT TestSetClientTLSErrors1232026/10/04 19:46:08 ERROR Upload failed error="bad path" count=3124=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1252026/10/04 19:46:08 ERROR Upload failed error=boom count=1126=== CONT TestFileTokenMissing127=== CONT TestGetStorePathHash1282026/10/04 19:46:08 ERROR Upload failed error=boom count=1129=== RUN TestGetStorePathHash/valid_store_path130=== CONT TestUploadMultipart_SupersededByPeer131=== RUN TestUploadMultipart_SupersededByPeer/exists1322026/10/04 19:46:08 ERROR Upload failed error="connection refused" count=20133=== PAUSE TestUploadMultipart_SupersededByPeer/exists1342026/10/04 19:46:08 ERROR Server seems unavailable, giving up on batch untried=171352026/10/04 19:46:08 WARN Rate limiter enabled after throttle name=server-test rate=5136=== RUN TestUploadMultipart_SupersededByPeer/missing137=== CONT TestParsePathInfoJSONMultiplePaths138=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths139=== PAUSE TestGetStorePathHash/valid_store_path140--- PASS: TestScriptTokenScriptFails (0.00s)141--- PASS: TestShellSplitErrors (0.00s)142=== CONT TestPathInfoHashCompatibility143=== PAUSE TestParsePathInfoJSON/Nix_format144=== CONT TestPathInfoCACompatibility145=== RUN TestPathInfoCACompatibility/null_ca_field146=== PAUSE TestPathInfoCACompatibility/null_ca_field147=== RUN TestPathInfoCACompatibility/old_string_format_-_text148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text149=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive150=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive151=== CONT TestConvertHashToNix32152=== CONT TestScriptTokenCachesUntilRefresh153=== RUN TestRateLimiterFeedback/429_enables_limiter154--- PASS: TestShellSplit (0.00s)155=== PAUSE TestUploadMultipart_SupersededByPeer/missing156=== RUN TestPathInfoCACompatibility/new_structured_format_-_text157=== CONT TestPartSizeForNAR158=== RUN TestPartSizeForNAR/zero_stays_at_minimum159=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum160=== RUN TestPartSizeForNAR/small_stays_at_minimum161=== PAUSE TestPartSizeForNAR/small_stays_at_minimum162=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum163=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum164=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts165=== CONT TestDumpPathWriterError166=== CONT TestFilterOversizedClosures1672026/10/04 19:46:08 WARN Rate limiter enabled after throttle name=server-test rate=5168=== RUN TestFilterOversizedClosures/no_limit_keeps_everything1692026/10/04 19:46:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:36167170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text172=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts173=== RUN TestPartSizeForNAR/1_TiB174=== PAUSE TestRateLimiterFeedback/429_enables_limiter175=== RUN TestConvertHashToNix32/SRI_format_to_Nix32176--- PASS: TestStaticToken (0.00s)177=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths178=== RUN TestGetStorePathHash/basename_without_hyphen_should_error179=== RUN TestParsePathInfoJSON/Lix_format180=== CONT TestEncodeNixBase32181=== CONT TestCaseHackSuffix182=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything183=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1842026/10/04 19:46:08 WARN Rate limiter backed off name=server-test rate=51852026/10/04 19:46:08 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:36167186--- PASS: TestEncodeNixBase32WithRealHash (0.00s)187=== PAUSE TestPartSizeForNAR/1_TiB188=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error189=== RUN TestRateLimiterFeedback/503_enables_limiter190=== PAUSE TestRateLimiterFeedback/503_enables_limiter191=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter192=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter193=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter194=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter195=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method196=== PAUSE TestParsePathInfoJSON/Lix_format197=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== RUN TestEncodeNixBase32/test_string_hash199=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32200=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped201=== RUN TestSetClientTLSErrors/missing_cert_file202=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon203=== CONT TestRegisterUploadedObjectReusesConnections204--- PASS: TestStreamPushReportsEveryPath (0.00s)205=== RUN TestPartSizeForNAR/5_TiB_S3_max_object206=== CONT TestDumpPathSingleFile207--- PASS: TestStreamPushIsolatesFailures (0.00s)208=== RUN TestParsePathInfoJSON/empty_input209=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method210=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object211=== CONT TestUploadMultipart_PartsInParallel212=== CONT TestFileTokenReadsAndCaches213=== PAUSE TestEncodeNixBase32/test_string_hash214=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error215=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths216=== PAUSE TestSetClientTLSErrors/missing_cert_file217--- PASS: TestStreamPushReportsSignatures (0.00s)218--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)219=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon220=== RUN TestSetClientTLS/rejects_connection_without_client_cert221=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert222=== CONT TestDumpPathMatchesNix223=== CONT TestUploadMultipart_SupersededByPeer/exists224=== RUN TestSetClientTLSErrors/missing_key_file225=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped226=== CONT TestUploadMultipart_SupersededByPeer/missing227=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error228=== RUN TestConvertHashToNix32/already_Nix32_format229=== RUN TestPartSizeForNAR/capped_at_5_GiB230=== RUN TestEncodeNixBase32/empty_input231=== PAUSE TestParsePathInfoJSON/empty_input232=== CONT TestRateLimiterFeedback/429_enables_limiter233=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter234--- PASS: TestFileTokenMissing (0.00s)235=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter236--- PASS: TestFileTokenEmpty (0.00s)237--- PASS: TestResolveStorePath (0.00s)238--- PASS: TestScriptTokenEmptyToken (0.00s)239--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)240--- PASS: TestScriptTokenBadJSON (0.00s)241--- PASS: TestDoServerRequestAttachesToken (0.01s)242--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)243--- PASS: TestFileTokenReadsAndCaches (0.00s)244--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)245=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI246=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA247=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA248=== RUN TestSetClientTLS/preserves_debug_logging_transport249=== PAUSE TestSetClientTLS/preserves_debug_logging_transport250=== RUN TestFilterOversizedClosures/all_closures_skipped251=== PAUSE TestFilterOversizedClosures/all_closures_skipped252=== PAUSE TestSetClientTLSErrors/missing_key_file253=== CONT TestPathInfoCACompatibility/null_ca_field254=== RUN TestSetClientTLSErrors/missing_ca_file255=== PAUSE TestSetClientTLSErrors/missing_ca_file256=== RUN TestSetClientTLSErrors/invalid_ca_file257=== PAUSE TestSetClientTLSErrors/invalid_ca_file258=== PAUSE TestConvertHashToNix32/already_Nix32_format259=== RUN TestConvertHashToNix32/invalid_format260=== CONT TestPathInfoCACompatibility/new_structured_format_-_text261=== PAUSE TestConvertHashToNix32/invalid_format262=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive263=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths265=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error266=== PAUSE TestEncodeNixBase32/empty_input267=== CONT TestSetClientTLS/preserves_debug_logging_transport268=== RUN TestParsePathInfoJSON/whitespace_only269=== PAUSE TestParsePathInfoJSON/whitespace_only270=== RUN TestParsePathInfoJSON/invalid_JSON271=== PAUSE TestParsePathInfoJSON/invalid_JSON272=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI273=== CONT TestRateLimiterFeedback/503_enables_limiter274=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512275=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512276=== CONT TestFilterOversizedClosures/all_closures_skipped277=== PAUSE TestPartSizeForNAR/capped_at_5_GiB2782026/10/04 19:46:08 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50279=== CONT TestPathInfoCACompatibility/old_string_format_-_text280=== CONT TestSetClientTLSErrors/invalid_ca_file281=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths282=== CONT TestSetClientTLSErrors/missing_ca_file283=== CONT TestSetClientTLS/rejects_connection_without_client_cert284=== CONT TestSetClientTLSErrors/missing_key_file285=== CONT TestConvertHashToNix32/SRI_format_to_Nix32286=== CONT TestConvertHashToNix32/invalid_format287=== CONT TestConvertHashToNix32/already_Nix32_format288=== CONT TestEncodeNixBase32/test_string_hash289=== CONT TestEncodeNixBase32/empty_input290=== CONT TestParsePathInfoJSON/Nix_format291=== CONT TestParsePathInfoJSON/invalid_JSON292=== CONT TestParsePathInfoJSON/empty_input293=== CONT TestParsePathInfoJSON/Lix_format294=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)295=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI296=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512297=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon298=== CONT TestPartSizeForNAR/zero_stays_at_minimum299=== CONT TestPartSizeForNAR/1_TiB300=== CONT TestPartSizeForNAR/capped_at_5_GiB301=== CONT TestPartSizeForNAR/5_TiB_S3_max_object302=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum303=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts304=== CONT TestPartSizeForNAR/small_stays_at_minimum305=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error306=== CONT TestGetStorePathHash/valid_store_path307=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3082026/10/04 19:46:08 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=2000309=== CONT TestParsePathInfoJSON/whitespace_only310--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)311--- PASS: TestPathInfoCACompatibility (0.01s)312 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)313 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)314 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)315 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)316 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)317=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error318=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error319=== CONT TestGetStorePathHash/basename_without_hyphen_should_error320=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA321--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)322 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)323 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)324=== CONT TestFilterOversizedClosures/no_limit_keeps_everything325=== CONT TestSetClientTLSErrors/missing_cert_file326--- PASS: TestConvertHashToNix32 (0.03s)327 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)328 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)329 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)330--- PASS: TestEncodeNixBase32 (0.03s)331 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)332 --- PASS: TestEncodeNixBase32/empty_input (0.00s)333--- PASS: TestSetClientTLSErrors (0.03s)334 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)336 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)337 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)338--- PASS: TestPathInfoHashCompatibility (0.03s)339 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)340 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)341 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)342 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)343--- PASS: TestPartSizeForNAR (0.03s)344 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)345 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)346 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)347 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)348 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)349 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)350 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)351--- PASS: TestGetStorePathHash (0.03s)352 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)353 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)354 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)355 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)356--- PASS: TestFilterOversizedClosures (0.03s)357 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)358 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)359 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)360--- PASS: TestParsePathInfoJSON (0.03s)361 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)362 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)363 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)364 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)365 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)3662026/10/04 19:46:08 WARN Rate limiter enabled after throttle name=server-test rate=53672026/10/04 19:46:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33939368--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)369 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)370 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3712026/10/04 19:46:08 WARN Rate limiter backed off name=server-test rate=53722026/10/04 19:46:08 WARN Rate limiter enabled after throttle name=server-test rate=53732026/10/04 19:46:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:436993742026/10/04 19:46:08 WARN Rate limiter backed off name=server-test rate=5375--- PASS: TestRateLimiterFeedback (0.01s)376 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3802026/10/04 19:46:08 http: TLS handshake error from 127.0.0.1:39382: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.03s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)385--- PASS: TestStreamPushRequestLine (0.05s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)387--- PASS: TestDumpPathWriterError (0.05s)388--- PASS: TestDumpPathSingleFile (0.06s)389--- PASS: TestCaseHackSuffix (0.06s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.07s)392--- PASS: TestUploadMultipart_PartsInParallel (0.64s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1524157100/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres1524157100/data -l logfile start422423/build/postgres1524157100:5432 - no response4242026-10-04 19:46:10.379 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-04 19:46:10.379 UTC [129] LOG: listening on Unix socket "/build/postgres1524157100/.s.PGSQL.5432"4262026-10-04 19:46:10.383 UTC [136] LOG: database system was shut down at 2026-10-04 19:46:10 UTC4272026-10-04 19:46:10.387 UTC [129] LOG: database system is ready to accept connections428/build/postgres1524157100:5432 - accepting connections429{"timestamp":"2026-10-04T19:46:10.578992608Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c9152a16-e54e-4366-a930-9938100bab7e","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestConnectWaitsForAPeerMigration471=== PAUSE TestConnectWaitsForAPeerMigration472=== RUN TestLeadElectsOneAndHandsOver473=== PAUSE TestLeadElectsOneAndHandsOver474=== RUN TestLeadIncumbentWinsAfterRestart4752026/10/04 19:46:10 INFO lead: acquired remote=192.0.2.1:12344762026/10/04 19:46:11 INFO lead: released remote=192.0.2.1:12344772026/10/04 19:46:11 INFO lead: acquired remote=192.0.2.1:12344782026/10/04 19:46:12 INFO lead: released remote=192.0.2.1:1234479--- PASS: TestLeadIncumbentWinsAfterRestart (2.28s)480=== RUN TestLeadEndsOnShutdown481=== PAUSE TestLeadEndsOnShutdown482=== RUN TestLeadEndsWhenItsConnectionHangs4832026/10/04 19:46:13 INFO lead: acquired remote=192.0.2.1:12344842026-10-04 19:46:14.460 UTC [385] FATAL: terminating connection due to administrator command4852026/10/04 19:46:14 INFO lead: acquired remote=192.0.2.1:12344862026/10/04 19:46:15 WARN lead: lock connection lost error="timeout: context deadline exceeded"4872026/10/04 19:46:15 INFO lead: released remote=192.0.2.1:12344882026/10/04 19:46:16 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadEndsWhenItsConnectionHangs (3.10s)490=== RUN TestGCAdvisoryLockBlocksConcurrentRun491=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun492=== RUN TestGCBugBareHashReferences493=== PAUSE TestGCBugBareHashReferences494=== RUN TestGCMetrics495=== PAUSE TestGCMetrics496=== RUN TestPushDedupSurvivesConcurrentGC497=== PAUSE TestPushDedupSurvivesConcurrentGC498=== RUN TestDeduplicatedObjectsRecordedAsPending499=== PAUSE TestDeduplicatedObjectsRecordedAsPending500=== RUN TestGCSweepSkipsPendingObjects501=== PAUSE TestGCSweepSkipsPendingObjects502=== RUN TestTombstonedObjectOfferedWithoutWaiting503=== PAUSE TestTombstonedObjectOfferedWithoutWaiting504=== RUN TestGCSweepDeliversEachKeyOnce505=== PAUSE TestGCSweepDeliversEachKeyOnce506=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection507=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection508=== RUN TestForceGCDuringPushOffersSweptObject509=== PAUSE TestForceGCDuringPushOffersSweptObject510=== RUN TestFailedS3DeleteKeepsTombstone511=== PAUSE TestFailedS3DeleteKeepsTombstone512=== RUN TestSweepSkipsRowsLockedByPush513=== PAUSE TestSweepSkipsRowsLockedByPush514=== RUN TestRegisterCompletedObjectNeedsPendingRow515=== PAUSE TestRegisterCompletedObjectNeedsPendingRow516=== RUN TestGetExistingObjectsLocksRows517=== PAUSE TestGetExistingObjectsLocksRows518=== RUN TestSweepRechecksPendingAfterLocking519=== PAUSE TestSweepRechecksPendingAfterLocking520=== RUN TestPushWaitsForSweepHoldingRow521=== PAUSE TestPushWaitsForSweepHoldingRow522=== RUN TestCommitRacingPendingCleanupKeepsObjects523=== PAUSE TestCommitRacingPendingCleanupKeepsObjects524=== RUN TestGCEndsOnShutdown525=== PAUSE TestGCEndsOnShutdown526=== RUN TestGCTaskStore_StartNew527=== PAUSE TestGCTaskStore_StartNew528=== RUN TestGCTaskStore_DeduplicateSameParams529=== PAUSE TestGCTaskStore_DeduplicateSameParams530=== RUN TestGCTaskStore_ConflictDifferentParams531=== PAUSE TestGCTaskStore_ConflictDifferentParams532=== RUN TestGCTaskStore_GetEmpty533=== PAUSE TestGCTaskStore_GetEmpty534=== RUN TestGCTaskStore_GetReturnsLatest535=== PAUSE TestGCTaskStore_GetReturnsLatest536=== RUN TestGCTaskStore_CompletedAllowsNewTask537=== PAUSE TestGCTaskStore_CompletedAllowsNewTask538=== RUN TestGCTaskStore_PhaseUpdates539=== PAUSE TestGCTaskStore_PhaseUpdates540=== RUN TestGCTaskStore_Fail541=== PAUSE TestGCTaskStore_Fail542=== RUN TestGracefulShutdownDrainsInflight543=== PAUSE TestGracefulShutdownDrainsInflight544=== RUN TestService_healthCheckHandler545=== PAUSE TestService_healthCheckHandler546=== RUN TestService_readinessHandler547=== PAUSE TestService_readinessHandler548=== RUN TestGenerateLandingPage549=== PAUSE TestGenerateLandingPage550=== RUN TestCacheConfigHandlerMaxNarSize551=== PAUSE TestCacheConfigHandlerMaxNarSize552=== RUN TestCreatePendingClosureRejectsOversizedNAR553=== PAUSE TestCreatePendingClosureRejectsOversizedNAR554=== RUN TestNARDeduplicationMetadataUploadBug555=== PAUSE TestNARDeduplicationMetadataUploadBug556=== RUN TestMetricsInventory557=== PAUSE TestMetricsInventory558=== RUN TestService_NativeMTLS559=== PAUSE TestService_NativeMTLS560=== RUN TestServerTLSConfig561=== PAUSE TestServerTLSConfig562=== RUN TestMultipartCleanup563=== PAUSE TestMultipartCleanup564=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded565=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded566=== RUN TestPendingCleanupUsesOneCutoff567=== PAUSE TestPendingCleanupUsesOneCutoff568=== RUN TestObjectStatsTrigger569=== PAUSE TestObjectStatsTrigger570=== RUN TestOrphanedObjectsGC571=== PAUSE TestOrphanedObjectsGC572=== RUN TestOrphanedObjectsGCStressTest573=== PAUSE TestOrphanedObjectsGCStressTest574=== RUN TestCreatePin_ReservedPins575=== PAUSE TestCreatePin_ReservedPins576=== RUN TestPresentReportsOnlyClosureRoots577=== PAUSE TestPresentReportsOnlyClosureRoots578=== RUN TestPresentNotReportedWhileGCDeletesClosure579=== PAUSE TestPresentNotReportedWhileGCDeletesClosure580=== RUN TestParseSingleRange581=== PAUSE TestParseSingleRange582=== RUN TestProxyHeadersOnlyTrustedOnSocket583=== PAUSE TestProxyHeadersOnlyTrustedOnSocket584=== RUN TestIsValidCachePath585=== PAUSE TestIsValidCachePath586=== RUN TestReadProxyNarinfo587=== PAUSE TestReadProxyNarinfo588=== RUN TestReadProxyNarinfoAlreadyDecompressed589=== PAUSE TestReadProxyNarinfoAlreadyDecompressed590=== RUN TestReadProxyNarStreaming591=== PAUSE TestReadProxyNarStreaming592=== RUN TestReadProxy404593=== PAUSE TestReadProxy404594=== RUN TestReadProxyInvalidPath595=== PAUSE TestReadProxyInvalidPath596=== RUN TestReadProxyHead597=== PAUSE TestReadProxyHead598=== RUN TestReadProxyOutlastsServerWriteTimeout599=== PAUSE TestReadProxyOutlastsServerWriteTimeout600=== RUN TestReadProxyConditionalGet601=== PAUSE TestReadProxyConditionalGet602=== RUN TestReadProxyRootRedirectsToIndexHTML603=== PAUSE TestReadProxyRootRedirectsToIndexHTML604=== RUN TestReadProxyDisabled605=== PAUSE TestReadProxyDisabled606=== RUN TestReadRedirectNar607=== PAUSE TestReadRedirectNar608=== RUN TestReadRedirectKeepsNarinfoProxied609=== PAUSE TestReadRedirectKeepsNarinfoProxied610=== RUN TestReadProxyRangeRequest611=== PAUSE TestReadProxyRangeRequest612=== RUN TestReadRedirectUsesPublicS3URL613=== PAUSE TestReadRedirectUsesPublicS3URL614=== RUN TestPush_OverlappingRootsStoreOneRowPerKey615=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey616=== RUN TestPush_CompleteCommitsEveryRoot617=== PAUSE TestPush_CompleteCommitsEveryRoot618=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit619=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit620=== RUN TestPush_RejectsBadRequests621=== PAUSE TestPush_RejectsBadRequests622=== RUN TestPush_SignsNarinfosOfItsPendingObjects623=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects624=== RUN TestRedundantMultipartUpload625=== PAUSE TestRedundantMultipartUpload626=== RUN TestCompleteMultipartUpload_ErrorButObjectExists627=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists628=== RUN TestCompletedNarNotReofferedAcrossClosures629=== PAUSE TestCompletedNarNotReofferedAcrossClosures630=== RUN TestPresignedUploadRegisteredBeforeCommit631=== PAUSE TestPresignedUploadRegisteredBeforeCommit632=== RUN TestService_Rustfstest633=== PAUSE TestService_Rustfstest634=== RUN TestParseSize635=== PAUSE TestParseSize636=== RUN TestSkippedUploadsHandler637=== PAUSE TestSkippedUploadsHandler638=== RUN TestSystemdListenerNotActivated639--- PASS: TestSystemdListenerNotActivated (0.00s)640=== RUN TestWatchdogBeatsWhenHealthy641--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)642=== RUN TestWatchdogSkipsWhenUnhealthy6432026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/04 19:46:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"653--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)654=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle655=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle656=== RUN TestProxyWriteTimeout657=== PAUSE TestProxyWriteTimeout658=== RUN TestPendingClosureWriteTimeout659=== PAUSE TestPendingClosureWriteTimeout660=== RUN TestIsValidUploadKey661=== PAUSE TestIsValidUploadKey662=== RUN TestUploadHandlersRejectInvalidKeys663=== PAUSE TestUploadHandlersRejectInvalidKeys664=== RUN TestUploadHandlersRejectOversizedBody665=== PAUSE TestUploadHandlersRejectOversizedBody666=== RUN TestService_cleanupPendingClosuresHandler667=== PAUSE TestService_cleanupPendingClosuresHandler668=== RUN TestService_createPendingClosureHandler669=== PAUSE TestService_createPendingClosureHandler670=== RUN TestService_verifyS3Integrity671=== PAUSE TestService_verifyS3Integrity672=== RUN TestCompleteMultipartUnregistered673=== PAUSE TestCompleteMultipartUnregistered674=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT675=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT676=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle677=== CONT TestCompletedNarNotReofferedAcrossClosures678=== CONT TestService_createPendingClosureHandler679=== CONT TestService_AuthMiddleware680=== CONT TestIsValidUploadKey681=== RUN TestIsValidUploadKey/narinfo682=== PAUSE TestIsValidUploadKey/narinfo683=== RUN TestIsValidUploadKey/nar_zst684=== CONT TestService_cleanupPendingClosuresHandler685=== CONT TestSkippedUploadsHandler686=== CONT TestParseSize687--- PASS: TestParseSize (0.00s)688=== CONT TestReadRedirectUsesPublicS3URL689=== CONT TestService_Rustfstest690=== CONT TestPresignedUploadRegisteredBeforeCommit6912026/10/04 19:46:16 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000692=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT693=== CONT TestCompleteMultipartUnregistered694=== CONT TestService_verifyS3Integrity695=== CONT TestUploadHandlersRejectOversizedBody696=== CONT TestUploadHandlersRejectInvalidKeys697=== CONT TestPendingClosureWriteTimeout698=== RUN TestPendingClosureWriteTimeout/empty699=== PAUSE TestPendingClosureWriteTimeout/empty700=== RUN TestPendingClosureWriteTimeout/400_objects701=== PAUSE TestPendingClosureWriteTimeout/400_objects702=== RUN TestPendingClosureWriteTimeout/670k_objects703=== CONT TestGCTaskStore_CompletedAllowsNewTask704--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)705=== CONT TestReadProxyRangeRequest706=== CONT TestCompleteMultipartUpload_ErrorButObjectExists707=== CONT TestRedundantMultipartUpload708=== CONT TestPush_SignsNarinfosOfItsPendingObjects709=== CONT TestPush_RejectsBadRequests710=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit711=== CONT TestPush_CompleteCommitsEveryRoot712=== CONT TestPush_OverlappingRootsStoreOneRowPerKey713=== PAUSE TestIsValidUploadKey/nar_zst714=== RUN TestIsValidUploadKey/nar_xz715=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info716=== PAUSE TestPendingClosureWriteTimeout/670k_objects717=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline718=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline719=== PAUSE TestIsValidUploadKey/nar_xz720=== RUN TestIsValidUploadKey/nar_plain721=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info722=== CONT TestReadRedirectKeepsNarinfoProxied723=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal724=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal725=== PAUSE TestIsValidUploadKey/nar_plain726=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key727=== RUN TestIsValidUploadKey/listing728=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key729=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key730=== PAUSE TestIsValidUploadKey/listing731=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key732=== RUN TestIsValidUploadKey/build_log733--- PASS: TestSkippedUploadsHandler (0.01s)734=== CONT TestReadRedirectNar735=== CONT TestReadProxyDisabled736=== PAUSE TestIsValidUploadKey/build_log737=== RUN TestIsValidUploadKey/build_log_home-manager_file738=== PAUSE TestIsValidUploadKey/build_log_home-manager_file739=== RUN TestIsValidUploadKey/build_log_plus_in_name740=== PAUSE TestIsValidUploadKey/build_log_plus_in_name741=== RUN TestIsValidUploadKey/build_log_question_mark742=== PAUSE TestIsValidUploadKey/build_log_question_mark743=== RUN TestIsValidUploadKey/build_log_equals744=== PAUSE TestIsValidUploadKey/build_log_equals745=== RUN TestIsValidUploadKey/realisation746=== PAUSE TestIsValidUploadKey/realisation747=== RUN TestIsValidUploadKey/realisation_plus_in_output748=== PAUSE TestIsValidUploadKey/realisation_plus_in_output749=== RUN TestIsValidUploadKey/nix-cache-info750=== PAUSE TestIsValidUploadKey/nix-cache-info751=== RUN TestIsValidUploadKey/index.html752=== PAUSE TestIsValidUploadKey/index.html753=== RUN TestIsValidUploadKey/narinfo_key,_nar_type754=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type755=== RUN TestIsValidUploadKey/nar_key,_narinfo_type756=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type757=== RUN TestIsValidUploadKey/listing_key,_narinfo_type758=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type759=== RUN TestIsValidUploadKey/traversal760=== PAUSE TestIsValidUploadKey/traversal761=== RUN TestIsValidUploadKey/traversal_nar762=== PAUSE TestIsValidUploadKey/traversal_nar763=== RUN TestIsValidUploadKey/absolute764=== PAUSE TestIsValidUploadKey/absolute765=== RUN TestIsValidUploadKey/empty_key766=== PAUSE TestIsValidUploadKey/empty_key767=== RUN TestIsValidUploadKey/unknown_type768=== PAUSE TestIsValidUploadKey/unknown_type769=== CONT TestReadProxyRootRedirectsToIndexHTML770=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure771=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure772=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart773=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart774=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts775=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts776=== CONT TestReadProxyConditionalGet7772026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures7782026/10/04 19:46:16 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"779--- PASS: TestService_AuthMiddleware (0.26s)780=== CONT TestReadProxyOutlastsServerWriteTimeout7812026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures7822026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures7832026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures7842026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures7852026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures7862026/10/04 19:46:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7872026/10/04 19:46:16 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7882026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures789--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.32s)790=== CONT TestReadProxyHead791--- PASS: TestReadRedirectUsesPublicS3URL (0.34s)792=== CONT TestReadProxyInvalidPath793--- PASS: TestService_Rustfstest (0.34s)794=== CONT TestReadProxy4047952026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures796--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.37s)797=== CONT TestReadProxyNarStreaming798--- PASS: TestReadProxyRangeRequest (0.39s)799=== CONT TestReadProxyNarinfoAlreadyDecompressed8002026/10/04 19:46:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8012026/10/04 19:46:16 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst802--- PASS: TestCompleteMultipartUnregistered (0.40s)803=== CONT TestReadProxyNarinfo8042026/10/04 19:46:16 INFO Received push request method=POST path=/api/pushes8052026/10/04 19:46:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8062026/10/04 19:46:16 INFO Signed narinfos id=1 count=1807--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.43s)808=== CONT TestGCAdvisoryLockBlocksConcurrentRun8092026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures8102026/10/04 19:46:16 INFO Received push request method=POST path=/api/pushes811--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.48s)812=== CONT TestIsValidCachePath813=== RUN TestIsValidCachePath/narinfo814=== PAUSE TestIsValidCachePath/narinfo815=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars816=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars817=== RUN TestIsValidCachePath/nar_zst818=== PAUSE TestIsValidCachePath/nar_zst819=== RUN TestIsValidCachePath/nar_xz820=== PAUSE TestIsValidCachePath/nar_xz821=== RUN TestIsValidCachePath/nar_bz2822=== PAUSE TestIsValidCachePath/nar_bz2823=== RUN TestIsValidCachePath/nar_uncompressed824=== PAUSE TestIsValidCachePath/nar_uncompressed825=== RUN TestIsValidCachePath/ls826=== PAUSE TestIsValidCachePath/ls827=== RUN TestIsValidCachePath/log828=== PAUSE TestIsValidCachePath/log829=== RUN TestIsValidCachePath/realisation830=== PAUSE TestIsValidCachePath/realisation831=== RUN TestIsValidCachePath/nix-cache-info832=== PAUSE TestIsValidCachePath/nix-cache-info833=== RUN TestIsValidCachePath/index.html834=== PAUSE TestIsValidCachePath/index.html835=== RUN TestIsValidCachePath/traversal_parent836=== PAUSE TestIsValidCachePath/traversal_parent837=== RUN TestIsValidCachePath/traversal_in_middle838=== PAUSE TestIsValidCachePath/traversal_in_middle839=== RUN TestIsValidCachePath/invalid_char_e840=== PAUSE TestIsValidCachePath/invalid_char_e841=== RUN TestIsValidCachePath/invalid_char_u842=== PAUSE TestIsValidCachePath/invalid_char_u843=== RUN TestIsValidCachePath/random_path844=== PAUSE TestIsValidCachePath/random_path845=== RUN TestIsValidCachePath/empty846=== PAUSE TestIsValidCachePath/empty847=== RUN TestIsValidCachePath/leading_slash848=== PAUSE TestIsValidCachePath/leading_slash849=== RUN TestIsValidCachePath/wrong_extension850=== PAUSE TestIsValidCachePath/wrong_extension851=== RUN TestIsValidCachePath/short_hash852=== PAUSE TestIsValidCachePath/short_hash853=== CONT TestGCTaskStore_GetReturnsLatest854--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)855=== CONT TestProxyHeadersOnlyTrustedOnSocket8562026/10/04 19:46:16 INFO Received push request method=POST path=/api/pushes8572026/10/04 19:46:16 INFO Received complete push request method=POST path=/api/pushes/1/complete8582026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures859--- PASS: TestPush_CompleteCommitsEveryRoot (0.50s)860=== CONT TestParseSingleRange861=== RUN TestParseSingleRange/none862=== PAUSE TestParseSingleRange/none863=== RUN TestParseSingleRange/unknown_unit864=== PAUSE TestParseSingleRange/unknown_unit865=== RUN TestParseSingleRange/multi-range_ignored866=== PAUSE TestParseSingleRange/multi-range_ignored867=== RUN TestParseSingleRange/malformed_no_dash868=== PAUSE TestParseSingleRange/malformed_no_dash869=== RUN TestParseSingleRange/malformed_both_empty870=== PAUSE TestParseSingleRange/malformed_both_empty871=== RUN TestParseSingleRange/malformed_end_before_start872=== PAUSE TestParseSingleRange/malformed_end_before_start873=== RUN TestParseSingleRange/closed874=== PAUSE TestParseSingleRange/closed875=== RUN TestParseSingleRange/open-ended876=== PAUSE TestParseSingleRange/open-ended877=== RUN TestParseSingleRange/end_clamped_to_size878=== PAUSE TestParseSingleRange/end_clamped_to_size879=== RUN TestParseSingleRange/suffix880=== PAUSE TestParseSingleRange/suffix881=== RUN TestParseSingleRange/suffix_exceeds_size882=== PAUSE TestParseSingleRange/suffix_exceeds_size883=== RUN TestParseSingleRange/single_byte884=== PAUSE TestParseSingleRange/single_byte885=== RUN TestParseSingleRange/start_past_EOF886=== PAUSE TestParseSingleRange/start_past_EOF887=== RUN TestParseSingleRange/start_far_past_EOF888=== PAUSE TestParseSingleRange/start_far_past_EOF889=== CONT TestGCTaskStore_GetEmpty890--- PASS: TestGCTaskStore_GetEmpty (0.00s)891=== CONT TestPresentNotReportedWhileGCDeletesClosure8922026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures8932026/10/04 19:46:16 INFO Received cleanup request method=DELETE path=/api/pending_closures8942026/10/04 19:46:16 INFO Aborted multipart uploads count=0 kept=08952026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures8962026/10/04 19:46:16 INFO Received cleanup request method=DELETE path=/api/pending_closures8972026/10/04 19:46:16 INFO Aborted multipart uploads count=1 kept=08982026/10/04 19:46:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8992026-10-04 19:46:16.831 UTC [469] ERROR: Closure does not exist: id=19002026-10-04 19:46:16.831 UTC [469] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9012026-10-04 19:46:16.831 UTC [469] STATEMENT: -- name: CommitPendingClosure :exec902 SELECT commit_pending_closure($1::bigint)903 904--- PASS: TestService_cleanupPendingClosuresHandler (0.54s)905=== CONT TestGCTaskStore_ConflictDifferentParams906--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)907=== CONT TestPresentReportsOnlyClosureRoots9082026/10/04 19:46:16 INFO Received push request method=POST path=/api/pushes9092026/10/04 19:46:16 INFO Received complete push request method=POST path=/api/pushes/1/complete9102026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures9112026/10/04 19:46:16 INFO Received push request method=POST path=/api/pushes9122026/10/04 19:46:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete913=== RUN TestPush_RejectsBadRequests/no_roots914=== PAUSE TestPush_RejectsBadRequests/no_roots915=== RUN TestPush_RejectsBadRequests/no_objects916=== PAUSE TestPush_RejectsBadRequests/no_objects917=== RUN TestPush_RejectsBadRequests/bad_root918=== PAUSE TestPush_RejectsBadRequests/bad_root919=== RUN TestPush_RejectsBadRequests/root_not_in_objects920=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects921=== CONT TestGCTaskStore_DeduplicateSameParams922--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)923=== CONT TestCreatePin_ReservedPins9242026/10/04 19:46:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9252026/10/04 19:46:16 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLmFkOGIzMGQ1LWI4YjEtNGI4Yi1iMWY1LWY0MWE1MjNlMmJjZXgxNzkxMTQzMTc2ODYwOTkxOTE19262026/10/04 19:46:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLjUyNDU2ZTc1LTc1YzgtNDQ5ZS04NWEzLWNlMzdkM2I5YTliM3gxNzkxMTQzMTc2NTgwMjI4NTkw parts=109272026/10/04 19:46:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9282026/10/04 19:46:16 INFO Completed upload id=19292026/10/04 19:46:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLmFkOGIzMGQ1LWI4YjEtNGI4Yi1iMWY1LWY0MWE1MjNlMmJjZXgxNzkxMTQzMTc2ODYwOTkxOTE1 parts=19302026/10/04 19:46:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009312026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures932--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.60s)933=== CONT TestGCTaskStore_StartNew934--- PASS: TestGCTaskStore_StartNew (0.00s)935=== CONT TestOrphanedObjectsGCStressTest9362026/10/04 19:46:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures937--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.55s)938=== CONT TestGCEndsOnShutdown9392026/10/04 19:46:16 INFO Aborted multipart uploads count=0 kept=09402026/10/04 19:46:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9412026/10/04 19:46:16 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=09422026/10/04 19:46:16 INFO Vacuumed table table=pending_closures9432026/10/04 19:46:16 INFO Vacuumed table table=pending_objects9442026/10/04 19:46:16 INFO Vacuumed table table=multipart_uploads945--- PASS: TestReadRedirectNar (0.57s)946=== CONT TestOrphanedObjectsGC9472026/10/04 19:46:16 INFO Vacuumed table table=closures9482026/10/04 19:46:16 INFO Aborted multipart uploads count=0 kept=09492026/10/04 19:46:16 INFO Vacuumed table table=objects9502026/10/04 19:46:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLmI3YjIwZmZkLWYwNDAtNDhjZS1hOWY1LWUyNjRiYWUwODc2ZXgxNzkxMTQzMTc2NTY3NDIwMDE2 parts=129512026/10/04 19:46:16 WARN Force mode enabled - objects will be deleted immediately without grace period9522026/10/04 19:46:16 INFO Received uploads request method=POST path=/api/pending_closures953--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.64s)954=== CONT TestCommitRacingPendingCleanupKeepsObjects955--- PASS: TestReadProxyDisabled (0.59s)956=== CONT TestObjectStatsTrigger9572026/10/04 19:46:16 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=09582026/10/04 19:46:16 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000959--- PASS: TestService_createPendingClosureHandler (0.66s)960=== CONT TestPushWaitsForSweepHoldingRow9612026/10/04 19:46:16 INFO Vacuumed table table=pending_closures9622026/10/04 19:46:16 INFO Vacuumed table table=pending_objects9632026/10/04 19:46:16 INFO Vacuumed table table=multipart_uploads9642026/10/04 19:46:16 INFO Vacuumed table table=closures9652026/10/04 19:46:16 INFO Vacuumed table table=objects9662026/10/04 19:46:16 INFO Received complete push request method=POST path=/api/pushes/2/complete967--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.67s)968=== CONT TestPendingCleanupUsesOneCutoff969--- PASS: TestReadRedirectKeepsNarinfoProxied (0.68s)970=== CONT TestSweepRechecksPendingAfterLocking971--- PASS: TestReadProxyConditionalGet (0.57s)972=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9732026/10/04 19:46:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9742026/10/04 19:46:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLmU1ZmEzN2Q4LWQxNjYtNDRjYS1iMDNmLWMwOGYwODc3OTU0M3gxNzkxMTQzMTc2NzM0NTU2MzA3 parts=109752026/10/04 19:46:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete976--- PASS: TestReadProxyHead (0.44s)977=== CONT TestGetExistingObjectsLocksRows9782026/10/04 19:46:17 INFO Completed upload id=19792026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures9802026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures9812026/10/04 19:46:17 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9822026/10/04 19:46:17 WARN Found objects in DB but missing from S3, will re-upload count=1983--- PASS: TestService_verifyS3Integrity (0.77s)984=== CONT TestMultipartCleanup985--- PASS: TestReadProxyInvalidPath (0.44s)986=== CONT TestRegisterCompletedObjectNeedsPendingRow9872026/10/04 19:46:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39795/oidc988--- PASS: TestReadProxy404 (0.48s)989=== CONT TestServerTLSConfig990=== RUN TestServerTLSConfig/no_client_CA991=== PAUSE TestServerTLSConfig/no_client_CA992=== RUN TestServerTLSConfig/missing_CA_file993=== PAUSE TestServerTLSConfig/missing_CA_file994=== RUN TestServerTLSConfig/not_a_PEM_file995=== PAUSE TestServerTLSConfig/not_a_PEM_file996=== CONT TestSweepSkipsRowsLockedByPush997--- PASS: TestReadProxyNarStreaming (0.46s)998=== CONT TestService_NativeMTLS999--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.46s)1000=== CONT TestFailedS3DeleteKeepsTombstone10012026/10/04 19:46:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1002--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.45s)1003=== CONT TestMetricsInventory10042026/10/04 19:46:17 INFO Starting HTTP server address=127.0.0.1:4189110052026/10/04 19:46:17 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3203019702/001/proxy.sock10062026/10/04 19:46:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLjYwOTA3ZjZmLTIxZWQtNDI3Ny04MzI4LTczNTc4YWUyYjI5OHgxNzkxMTQzMTc2ODA1MjM4MTE4 parts=1210072026/10/04 19:46:17 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10082026/10/04 19:46:17 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10092026/10/04 19:46:17 INFO Shutdown signal received, draining in-flight requests timeout=10s10102026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures1011--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.43s)1012=== CONT TestForceGCDuringPushOffersSweptObject1013=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1014=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1015=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1016=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1017=== CONT TestNARDeduplicationMetadataUploadBug10182026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures1019--- PASS: TestPresentReportsOnlyClosureRoots (0.42s)1020=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1021--- PASS: TestGCEndsOnShutdown (0.44s)1022=== CONT TestCreatePendingClosureRejectsOversizedNAR10232026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures1024--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1025=== CONT TestGCSweepDeliversEachKeyOnce10262026/10/04 19:46:17 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161027--- PASS: TestReadProxyNarinfo (0.68s)1028=== CONT TestCacheConfigHandlerMaxNarSize1029--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1030=== CONT TestClientMultipleUploads10312026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=01032--- PASS: TestObjectStatsTrigger (0.47s)1033=== CONT TestGenerateLandingPage10342026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period1035--- PASS: TestGenerateLandingPage (0.00s)1036=== CONT TestService_readinessHandler10372026/10/04 19:46:17 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=010382026/10/04 19:46:17 INFO Vacuumed table table=pending_closures10392026/10/04 19:46:17 INFO Vacuumed table table=pending_objects10402026/10/04 19:46:17 INFO Vacuumed table table=multipart_uploads10412026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures10422026/10/04 19:46:17 INFO Vacuumed table table=closures10432026/10/04 19:46:17 INFO Vacuumed table table=objects1044--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.49s)1045=== CONT TestLeadEndsOnShutdown10462026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=010472026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period10482026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures10492026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures10512026/10/04 19:46:17 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=010522026/10/04 19:46:17 INFO Vacuumed table table=pending_closures10532026/10/04 19:46:17 INFO Vacuumed table table=pending_objects10542026/10/04 19:46:17 INFO Vacuumed table table=multipart_uploads10552026/10/04 19:46:17 INFO Vacuumed table table=closures10562026/10/04 19:46:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10572026/10/04 19:46:17 INFO Vacuumed table table=objects1058--- PASS: TestSweepRechecksPendingAfterLocking (0.51s)1059=== CONT TestService_healthCheckHandler1060--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.49s)1061=== CONT TestTombstonedObjectOfferedWithoutWaiting10622026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures1063--- PASS: TestGetExistingObjectsLocksRows (0.47s)1064=== CONT TestLeadElectsOneAndHandsOver10652026/10/04 19:46:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10662026/10/04 19:46:17 WARN Refused reserved pin name=worker-x86_64-linux10672026/10/04 19:46:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10682026/10/04 19:46:17 INFO Received create pin request method=POST path=/api/pins/my-app10692026/10/04 19:46:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1070--- PASS: TestCreatePin_ReservedPins (0.66s)1071=== CONT TestGCSweepSkipsPendingObjects1072--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.48s)1073=== CONT TestGracefulShutdownDrainsInflight10742026/10/04 19:46:17 INFO Starting HTTP server address=127.0.0.1:3623510752026/10/04 19:46:17 INFO Shutdown signal received, draining in-flight requests timeout=10s10762026/10/04 19:46:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10772026/10/04 19:46:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1078--- PASS: TestService_NativeMTLS (0.45s)1079=== CONT TestDeduplicatedObjectsRecordedAsPending10802026/10/04 19:46:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10812026/10/04 19:46:17 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket47/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10822026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=110832026/10/04 19:46:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10842026/10/04 19:46:17 INFO Aborted multipart uploads count=1 kept=01085--- PASS: TestMultipartCleanup (0.55s)1086=== CONT TestConnectWaitsForAPeerMigration10872026/10/04 19:46:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1088--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1089=== CONT TestGCTaskStore_Fail1090--- PASS: TestGCTaskStore_Fail (0.00s)1091=== CONT TestPushDedupSurvivesConcurrentGC10922026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=010932026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period10942026/10/04 19:46:17 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLjc4MTE4NjA2LTVkODEtNDNmOS1hYjNiLTMzMDBiN2RhODNhMXgxNzkxMTQzMTc3MjA2NzM1MTQw error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10952026/10/04 19:46:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjRlZTJiNjItMTgyZi00NzVmLTgxMDctMWY2YWRiOTM3MDdlLmY3OTk4OTdlLTkzZjktNDcyNy1iNGJiLTE4M2NiMjI5ZTJlYXgxNzkxMTQzMTc3MjAwMzM5NTgy parts=1210962026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures10972026/10/04 19:46:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10982026/10/04 19:46:17 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=010992026/10/04 19:46:17 INFO Vacuumed table table=pending_closures11002026/10/04 19:46:17 INFO Vacuumed table table=pending_objects11012026/10/04 19:46:17 INFO Vacuumed table table=multipart_uploads11022026/10/04 19:46:17 INFO Vacuumed table table=closures11032026/10/04 19:46:17 INFO Aborted multipart uploads count=1 kept=011042026/10/04 19:46:17 INFO Vacuumed table table=objects1105--- PASS: TestRedundantMultipartUpload (1.34s)1106=== CONT TestGCTaskStore_PhaseUpdates1107--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1108=== CONT TestResolveDBConnectionString1109=== RUN TestResolveDBConnectionString/flag_wins1110=== PAUSE TestResolveDBConnectionString/flag_wins1111=== RUN TestResolveDBConnectionString/file_when_flag_empty1112=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1113=== RUN TestResolveDBConnectionString/missing_file_is_an_error1114=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1115=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1116=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1117=== RUN TestResolveDBConnectionString/nothing_configured1118=== PAUSE TestResolveDBConnectionString/nothing_configured1119=== CONT TestGCMetrics11202026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=011212026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period11222026/10/04 19:46:17 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=011232026/10/04 19:46:17 INFO Vacuumed table table=pending_closures11242026/10/04 19:46:17 INFO Vacuumed table table=pending_objects11252026/10/04 19:46:17 INFO Vacuumed table table=multipart_uploads11262026/10/04 19:46:17 INFO Vacuumed table table=closures11272026/10/04 19:46:17 INFO Vacuumed table table=objects1128--- PASS: TestSweepSkipsRowsLockedByPush (0.55s)1129=== CONT TestGCBugBareHashReferences1130--- PASS: TestMetricsInventory (0.49s)1131=== CONT TestClientIntegration1132=== NAME TestOrphanedObjectsGC1133 orphaned_objects_gc_test.go:290: GC Test Summary:1134 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1135 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1136 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1137 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1138 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1139--- PASS: TestOrphanedObjectsGC (0.76s)1140=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11412026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures11422026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=011432026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period1144=== NAME TestNARDeduplicationMetadataUploadBug1145 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2847236907/001/store/4ifjix810hs9ich8522am9171bi789ms-file1.txt11462026/10/04 19:46:17 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11472026/10/04 19:46:17 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1148--- PASS: TestFailedS3DeleteKeepsTombstone (0.58s)1149=== CONT TestClientCADerivations1150--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.93s)1151=== CONT TestCacheStatsHandler11522026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=011532026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period11542026/10/04 19:46:17 WARN readiness check failed error="closed pool"1155--- PASS: TestService_readinessHandler (0.36s)1156=== CONT TestService_ReadScope_PublicByDefault11572026/10/04 19:46:17 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=011582026/10/04 19:46:17 INFO Vacuumed table table=pending_closures11592026/10/04 19:46:17 INFO Vacuumed table table=pending_objects11602026/10/04 19:46:17 INFO Vacuumed table table=multipart_uploads11612026/10/04 19:46:17 INFO Vacuumed table table=closures11622026/10/04 19:46:17 INFO Vacuumed table table=objects1163--- PASS: TestGCSweepDeliversEachKeyOnce (0.43s)1164=== CONT TestClientErrorHandling1165=== RUN TestClientErrorHandling/InvalidStorePath1166=== PAUSE TestClientErrorHandling/InvalidStorePath1167=== RUN TestClientErrorHandling/InvalidAuthToken1168=== PAUSE TestClientErrorHandling/InvalidAuthToken1169=== RUN TestClientErrorHandling/ServerNotAvailable1170=== PAUSE TestClientErrorHandling/ServerNotAvailable1171=== CONT TestCacheConfigHandler1172=== RUN TestCacheConfigHandler/full_config,_no_issuer1173=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1174=== RUN TestCacheConfigHandler/no_cache_url_configured1175=== PAUSE TestCacheConfigHandler/no_cache_url_configured1176=== RUN TestCacheConfigHandler/no_signing_keys1177=== PAUSE TestCacheConfigHandler/no_signing_keys1178=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1179=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1180=== CONT TestClientSharedPathCommittedMidPush1181=== NAME TestClientMultipleUploads1182 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads438852050/001/store/g0kgf6ihbqx5x3w1kv3dnjzqhv8n5y1k-test-file-0.txt11832026/10/04 19:46:17 INFO lead: acquired remote=192.0.2.1:123411842026/10/04 19:46:17 INFO Received push request method=POST path=/api/pushes11852026/10/04 19:46:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11862026/10/04 19:46:17 INFO Uploading 4ifjix810hs9ich8522am9171bi789ms-file1.txt (160B)1187--- PASS: TestService_healthCheckHandler (0.33s)1188=== CONT TestProxyWriteTimeout1189=== RUN TestProxyWriteTimeout/narinfo1190=== PAUSE TestProxyWriteTimeout/narinfo1191=== RUN TestProxyWriteTimeout/1_GiB_nar1192=== PAUSE TestProxyWriteTimeout/1_GiB_nar1193=== RUN TestProxyWriteTimeout/10_GiB_nar1194=== PAUSE TestProxyWriteTimeout/10_GiB_nar1195=== RUN TestProxyWriteTimeout/unknown_size1196=== PAUSE TestProxyWriteTimeout/unknown_size1197=== CONT TestClientWithDependencies11982026/10/04 19:46:17 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11992026/10/04 19:46:17 WARN Failed to register uploaded object key=4ifjix810hs9ich8522am9171bi789ms.ls error="server returned 404: 404 page not found\n"12002026/10/04 19:46:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12012026/10/04 19:46:17 INFO Signed narinfos id=1 count=112022026/10/04 19:46:17 INFO Uploading 1 narinfos12032026/10/04 19:46:17 INFO Received complete push request method=POST path=/api/pushes/1/complete12042026/10/04 19:46:17 WARN Failed to register uploaded object key=4ifjix810hs9ich8522am9171bi789ms.narinfo error="server returned 404: 404 page not found\n"1205=== NAME TestClientMultipleUploads1206 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads438852050/001/store/gb5mh0l6z8r7jpplv1138x9kq31qkxcc-test-file-1.txt12072026/10/04 19:46:17 INFO Upload complete. (59ms)1208=== NAME TestNARDeduplicationMetadataUploadBug1209 metadata_upload_test.go:54: Retrieved narinfo from S3:1210 StorePath: /build/TestNARDeduplicationMetadataUploadBug2847236907/001/store/4ifjix810hs9ich8522am9171bi789ms-file1.txt1211 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1212 Compression: zstd1213 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1214 NarSize: 1601215 References: 1216 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1217 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1218 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1219 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12202026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures1221--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.35s)1222=== CONT TestClientFallsBackToClosures1223=== NAME TestClientMultipleUploads1224 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads438852050/001/store/vfdf1nqhxdscclyv1yb7fsr3849lkh5a-test-file-2.txt12252026/10/04 19:46:17 INFO lead: acquired remote=192.0.2.1:12341226=== NAME TestNARDeduplicationMetadataUploadBug1227 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2847236907/001/store/6d1v37rhnm668pghxx09hw069z69dis3-file2.txt12282026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures12292026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=012302026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period12312026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures12322026/10/04 19:46:17 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=01233--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.33s)1234=== CONT TestService_ReadAuthMiddleware12352026/10/04 19:46:17 INFO Vacuumed table table=pending_closures12362026/10/04 19:46:17 INFO Vacuumed table table=pending_objects12372026/10/04 19:46:17 INFO Vacuumed table table=multipart_uploads12382026/10/04 19:46:17 INFO Vacuumed table table=closures12392026/10/04 19:46:17 INFO Vacuumed table table=objects1240--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.66s)1241=== CONT TestClientPushesUseOnePush1242--- PASS: TestGCSweepSkipsPendingObjects (0.37s)1243=== CONT TestService_RequireScope_OIDC12442026/10/04 19:46:17 INFO Received push request method=POST path=/api/pushes12452026/10/04 19:46:17 INFO Received push request method=POST path=/api/pushes12462026/10/04 19:46:17 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1247--- PASS: TestPushWaitsForSweepHoldingRow (0.97s)1248=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12492026/10/04 19:46:17 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12502026/10/04 19:46:17 INFO Uploading gb5mh0l6z8r7jpplv1138x9kq31qkxcc-test-file-1.txt (160B)12512026/10/04 19:46:17 INFO Uploading g0kgf6ihbqx5x3w1kv3dnjzqhv8n5y1k-test-file-0.txt (160B)12522026/10/04 19:46:17 INFO Uploading vfdf1nqhxdscclyv1yb7fsr3849lkh5a-test-file-2.txt (160B)12532026/10/04 19:46:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12542026/10/04 19:46:17 INFO Signed narinfos id=2 count=112552026/10/04 19:46:17 WARN Failed to register uploaded object key=6d1v37rhnm668pghxx09hw069z69dis3.ls error="server returned 404: 404 page not found\n"12562026/10/04 19:46:17 INFO Uploading 1 narinfos12572026/10/04 19:46:17 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12582026/10/04 19:46:17 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12592026/10/04 19:46:17 INFO Received complete push request method=POST path=/api/pushes/2/complete12602026/10/04 19:46:17 WARN Failed to register uploaded object key=g0kgf6ihbqx5x3w1kv3dnjzqhv8n5y1k.ls error="server returned 404: 404 page not found\n"12612026/10/04 19:46:17 WARN Failed to register uploaded object key=vfdf1nqhxdscclyv1yb7fsr3849lkh5a.ls error="server returned 404: 404 page not found\n"12622026/10/04 19:46:17 WARN Failed to register uploaded object key=gb5mh0l6z8r7jpplv1138x9kq31qkxcc.ls error="server returned 404: 404 page not found\n"12632026/10/04 19:46:17 WARN Failed to register uploaded object key=6d1v37rhnm668pghxx09hw069z69dis3.narinfo error="server returned 404: 404 page not found\n"12642026/10/04 19:46:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12652026/10/04 19:46:17 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12662026/10/04 19:46:17 INFO Signed narinfos id=1 count=312672026/10/04 19:46:17 INFO Uploading 3 narinfos12682026/10/04 19:46:17 WARN Failed to register uploaded object key=g0kgf6ihbqx5x3w1kv3dnjzqhv8n5y1k.narinfo error="server returned 404: 404 page not found\n"12692026/10/04 19:46:17 INFO Received complete push request method=POST path=/api/pushes/1/complete12702026/10/04 19:46:17 WARN Failed to register uploaded object key=vfdf1nqhxdscclyv1yb7fsr3849lkh5a.narinfo error="server returned 404: 404 page not found\n"12712026/10/04 19:46:17 WARN Failed to register uploaded object key=gb5mh0l6z8r7jpplv1138x9kq31qkxcc.narinfo error="server returned 404: 404 page not found\n"12722026/10/04 19:46:17 INFO Upload complete. (50ms)12732026/10/04 19:46:17 INFO Received uploads request method=POST path=/api/pending_closures1274=== NAME TestNARDeduplicationMetadataUploadBug1275 metadata_upload_test.go:76: Retrieved narinfo from S3:1276 StorePath: /build/TestNARDeduplicationMetadataUploadBug2847236907/001/store/6d1v37rhnm668pghxx09hw069z69dis3-file2.txt1277 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1278 Compression: zstd1279 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1280 NarSize: 1601281 References: 1282 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1283 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1284 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1285 {"version":1,"root":{"type":"regular","size":44}}12862026/10/04 19:46:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36021/oidc12872026/10/04 19:46:17 INFO Upload complete. (58ms)1288=== NAME TestClientMultipleUploads1289 client_integration_test.go:369: Uploaded 3 paths in 88.885113ms1290--- PASS: TestNARDeduplicationMetadataUploadBug (0.74s)1291=== CONT TestService_AuthMiddleware_MTLSProxyHeader12922026/10/04 19:46:17 INFO Aborted multipart uploads count=0 kept=012932026/10/04 19:46:17 WARN Force mode enabled - objects will be deleted immediately without grace period1294--- PASS: TestClientMultipleUploads (0.57s)1295=== CONT TestService_AuthMiddleware_OIDC12962026/10/04 19:46:17 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=012972026/10/04 19:46:17 INFO Vacuumed table table=pending_closures12982026/10/04 19:46:17 INFO Vacuumed table table=pending_objects12992026/10/04 19:46:17 INFO Vacuumed table table=multipart_uploads13002026/10/04 19:46:17 INFO Vacuumed table table=closures13012026/10/04 19:46:17 INFO Vacuumed table table=objects1302--- PASS: TestGCMetrics (0.31s)1303=== CONT TestPinProtectsFromGC1304=== NAME TestClientIntegration1305 client_integration_test.go:286: Created store path: /build/TestClientIntegration2635088739/002/store/wyszsg7m3cpvyqlw9gsvc7hrp0ag03gp-test-file.txt13062026/10/04 19:46:18 INFO Aborted multipart uploads count=0 kept=013072026/10/04 19:46:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013082026/10/04 19:46:18 INFO Vacuumed table table=pending_closures13092026/10/04 19:46:18 INFO Vacuumed table table=pending_objects13102026/10/04 19:46:18 INFO Vacuumed table table=multipart_uploads13112026/10/04 19:46:18 INFO Vacuumed table table=closures13122026/10/04 19:46:18 INFO Vacuumed table table=objects13132026/10/04 19:46:18 INFO Aborted multipart uploads count=0 kept=013142026/10/04 19:46:18 WARN Force mode enabled - objects will be deleted immediately without grace period13152026/10/04 19:46:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013162026/10/04 19:46:18 INFO Vacuumed table table=pending_closures13172026/10/04 19:46:18 INFO Vacuumed table table=pending_objects13182026/10/04 19:46:18 INFO Vacuumed table table=multipart_uploads13192026/10/04 19:46:18 INFO Vacuumed table table=closures13202026/10/04 19:46:18 INFO Vacuumed table table=objects1321--- PASS: TestPushDedupSurvivesConcurrentGC (0.41s)1322=== CONT TestPendingClosureWriteTimeout/empty1323=== CONT TestPendingClosureWriteTimeout/670k_objects1324=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline13252026/10/04 19:46:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42437/oidc1326--- PASS: TestCacheStatsHandler (0.32s)1327=== CONT TestPendingClosureWriteTimeout/400_objects1328=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13292026/10/04 19:46:18 INFO Received uploads request method=POST path=/1330=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13312026/10/04 19:46:18 INFO Received complete multipart upload request method=POST path=/1332=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13332026/10/04 19:46:18 INFO Received request for more parts method=POST path=/1334=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13352026/10/04 19:46:18 INFO Received uploads request method=POST path=/1336--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1337 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1338 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1339 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1340 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1341=== CONT TestIsValidUploadKey/narinfo1342=== CONT TestIsValidUploadKey/realisation_plus_in_output1343=== CONT TestIsValidUploadKey/unknown_type1344=== CONT TestIsValidUploadKey/empty_key1345=== CONT TestIsValidUploadKey/absolute1346=== CONT TestIsValidUploadKey/traversal_nar1347=== CONT TestIsValidUploadKey/traversal1348=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1349=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1350=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1351=== CONT TestIsValidUploadKey/index.html1352=== CONT TestIsValidUploadKey/nix-cache-info1353=== CONT TestIsValidUploadKey/build_log_home-manager_file1354=== CONT TestIsValidUploadKey/realisation1355=== CONT TestIsValidUploadKey/build_log_equals1356=== CONT TestIsValidUploadKey/build_log_question_mark1357=== CONT TestIsValidUploadKey/build_log_plus_in_name1358=== CONT TestIsValidUploadKey/nar_plain1359=== CONT TestIsValidUploadKey/build_log1360=== CONT TestIsValidUploadKey/listing1361=== CONT TestIsValidUploadKey/nar_zst1362=== CONT TestIsValidUploadKey/nar_xz1363=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13642026/10/04 19:46:18 INFO Received uploads request method=POST path=/1365--- PASS: TestIsValidUploadKey (0.06s)1366 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1367 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1368 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1369 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1370 --- PASS: TestIsValidUploadKey/absolute (0.00s)1371 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1372 --- PASS: TestIsValidUploadKey/traversal (0.00s)1373 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1374 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1375 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1376 --- PASS: TestIsValidUploadKey/index.html (0.00s)1377 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1378 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1379 --- PASS: TestIsValidUploadKey/realisation (0.00s)1380 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1381 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1382 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1383 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1384 --- PASS: TestIsValidUploadKey/build_log (0.00s)1385 --- PASS: TestIsValidUploadKey/listing (0.00s)1386 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1387 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1388--- PASS: TestService_ReadScope_PublicByDefault (0.29s)1389=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13902026/10/04 19:46:18 INFO Received request for more parts method=POST path=/13912026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes13922026/10/04 19:46:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/10/04 19:46:18 INFO Uploading wyszsg7m3cpvyqlw9gsvc7hrp0ag03gp-test-file.txt (152B)13942026/10/04 19:46:18 WARN Failed to register uploaded object key=wyszsg7m3cpvyqlw9gsvc7hrp0ag03gp.ls error="server returned 404: 404 page not found\n"13952026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13962026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13972026/10/04 19:46:18 INFO Signed narinfos id=1 count=113982026/10/04 19:46:18 INFO Uploading 1 narinfos13992026/10/04 19:46:18 INFO Received complete push request method=POST path=/api/pushes/1/complete14002026/10/04 19:46:18 WARN Failed to register uploaded object key=wyszsg7m3cpvyqlw9gsvc7hrp0ag03gp.narinfo error="server returned 404: 404 page not found\n"14012026/10/04 19:46:18 INFO Upload complete. (59ms)1402=== NAME TestClientCADerivations1403 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2362419643/001/store/wan1k6iac4f4v7zacbx0lzr3a558af0s-ca-test1404=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14052026/10/04 19:46:18 INFO Received complete multipart upload request method=POST path=/14062026/10/04 19:46:18 INFO All 1 paths already cached1407=== NAME TestClientIntegration1408 client_integration_test.go:312: Retrieved narinfo from S3:1409 StorePath: /build/TestClientIntegration2635088739/002/store/wyszsg7m3cpvyqlw9gsvc7hrp0ag03gp-test-file.txt1410 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1411 Compression: zstd1412 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11413 NarSize: 1521414 References: 1415 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11416 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1417 client_integration_test.go:313: Decompressed .ls content (64 bytes):1418 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1419 client_integration_test.go:316: Testing garbage collection...1420--- PASS: TestService_ReadAuthMiddleware (0.23s)1421=== CONT TestIsValidCachePath/narinfo1422=== CONT TestIsValidCachePath/index.html1423=== CONT TestIsValidCachePath/short_hash1424=== CONT TestIsValidCachePath/wrong_extension1425=== CONT TestIsValidCachePath/leading_slash1426=== CONT TestIsValidCachePath/empty1427=== CONT TestIsValidCachePath/random_path1428=== CONT TestIsValidCachePath/invalid_char_u1429=== CONT TestIsValidCachePath/invalid_char_e1430=== CONT TestIsValidCachePath/traversal_in_middle1431=== CONT TestIsValidCachePath/traversal_parent1432=== CONT TestIsValidCachePath/nar_uncompressed1433=== CONT TestIsValidCachePath/nar_xz1434=== CONT TestIsValidCachePath/nix-cache-info1435=== CONT TestIsValidCachePath/nar_bz21436=== CONT TestIsValidCachePath/realisation1437=== CONT TestIsValidCachePath/log1438=== CONT TestIsValidCachePath/ls1439=== CONT TestIsValidCachePath/nar_zst1440=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1441--- PASS: TestIsValidCachePath (0.00s)1442 --- PASS: TestIsValidCachePath/narinfo (0.00s)1443 --- PASS: TestIsValidCachePath/index.html (0.00s)1444 --- PASS: TestIsValidCachePath/short_hash (0.00s)1445 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1446 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1447 --- PASS: TestIsValidCachePath/empty (0.00s)1448 --- PASS: TestIsValidCachePath/random_path (0.00s)1449 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1450 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1451 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1452 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1453 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1454 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1455 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1456 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1457 --- PASS: TestIsValidCachePath/realisation (0.00s)1458 --- PASS: TestIsValidCachePath/log (0.00s)1459 --- PASS: TestIsValidCachePath/ls (0.00s)1460 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1461 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1462=== CONT TestParseSingleRange/none1463=== CONT TestParseSingleRange/open-ended1464=== CONT TestParseSingleRange/start_far_past_EOF1465=== CONT TestParseSingleRange/start_past_EOF1466=== CONT TestParseSingleRange/single_byte1467=== CONT TestParseSingleRange/suffix_exceeds_size1468=== CONT TestParseSingleRange/end_clamped_to_size1469=== CONT TestParseSingleRange/malformed_both_empty1470=== CONT TestParseSingleRange/closed1471=== CONT TestParseSingleRange/suffix1472=== CONT TestParseSingleRange/malformed_end_before_start1473=== CONT TestParseSingleRange/multi-range_ignored1474=== CONT TestParseSingleRange/unknown_unit1475=== CONT TestParseSingleRange/malformed_no_dash1476--- PASS: TestParseSingleRange (0.00s)1477 --- PASS: TestParseSingleRange/none (0.00s)1478 --- PASS: TestParseSingleRange/open-ended (0.00s)1479 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1480 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1481 --- PASS: TestParseSingleRange/single_byte (0.00s)1482 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1483 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1484 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1485 --- PASS: TestParseSingleRange/closed (0.00s)1486 --- PASS: TestParseSingleRange/suffix (0.00s)1487 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1488 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1489 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1490 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1491=== CONT TestPush_RejectsBadRequests/no_roots14922026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes1493=== CONT TestPush_RejectsBadRequests/bad_root14942026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes1495=== CONT TestPush_RejectsBadRequests/root_not_in_objects14962026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes1497=== CONT TestPush_RejectsBadRequests/no_objects14982026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes1499=== CONT TestServerTLSConfig/no_client_CA1500=== CONT TestServerTLSConfig/missing_CA_file1501=== CONT TestServerTLSConfig/not_a_PEM_file1502--- PASS: TestPush_RejectsBadRequests (0.58s)1503 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1504 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1505 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1506 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1507=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1508--- PASS: TestServerTLSConfig (0.00s)1509 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1510 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1511 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1512=== NAME TestClientCADerivations1513 client_ca_test.go:139: Found 1 dependencies (including self)1514=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15152026/10/04 19:46:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures15162026/10/04 19:46:18 INFO Garbage collection started15172026/10/04 19:46:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15182026/10/04 19:46:18 WARN mTLS auth: bound subjects configured but subject DN unavailable15192026/10/04 19:46:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1520--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.26s)1521=== CONT TestResolveDBConnectionString/flag_wins1522=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1523=== CONT TestResolveDBConnectionString/nothing_configured1524=== CONT TestResolveDBConnectionString/missing_file_is_an_error1525=== CONT TestResolveDBConnectionString/file_when_flag_empty1526=== CONT TestClientErrorHandling/InvalidStorePath1527--- PASS: TestResolveDBConnectionString (0.00s)1528 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1529 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1530 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1531 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1532 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)15332026/10/04 19:46:18 INFO Aborted multipart uploads count=0 kept=015342026/10/04 19:46:18 WARN Force mode enabled - objects will be deleted immediately without grace period1535=== NAME TestClientWithDependencies1536 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2177042331/001/store/as8sp4105mlkhfcij1ppvr5lygrpyjlr-test-script1537--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.25s)1538=== CONT TestClientErrorHandling/ServerNotAvailable15392026/10/04 19:46:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=015402026/10/04 19:46:18 INFO Vacuumed table table=pending_closures15412026/10/04 19:46:18 INFO Vacuumed table table=pending_objects15422026/10/04 19:46:18 INFO Vacuumed table table=multipart_uploads15432026/10/04 19:46:18 INFO Vacuumed table table=closures1544--- PASS: TestGCBugBareHashReferences (0.56s)1545=== CONT TestClientErrorHandling/InvalidAuthToken15462026/10/04 19:46:18 INFO Vacuumed table table=objects1547=== NAME TestClientWithDependencies1548 client_integration_test.go:615: Found 1 dependencies (including self)15492026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes15502026/10/04 19:46:18 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15512026/10/04 19:46:18 INFO Uploading dl099iczm5nzal2kxkazcibzjxp2pzia-top (224B)15522026/10/04 19:46:18 INFO Uploading cd10adhwsmjjzkpwz4anhk27mg0v3dbr-shared-dep (136B)15532026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15542026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/1qy7qznaa7c47d10b2l7gl5ry53la7r63lqymg0l2298744yvvda.nar.zst error="server returned 404: 404 page not found\n"15552026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15562026/10/04 19:46:18 WARN Failed to register uploaded object key=dl099iczm5nzal2kxkazcibzjxp2pzia.ls error="server returned 404: 404 page not found\n"15572026/10/04 19:46:18 WARN Failed to register uploaded object key=cd10adhwsmjjzkpwz4anhk27mg0v3dbr.ls error="server returned 404: 404 page not found\n"15582026/10/04 19:46:18 INFO Signed narinfos id=1 count=215592026/10/04 19:46:18 INFO Uploading 2 narinfos1560=== RUN TestService_RequireScope_OIDC/builder_may_write1561=== PAUSE TestService_RequireScope_OIDC/builder_may_write1562=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1563=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1564=== RUN TestService_RequireScope_OIDC/ops_may_admin1565=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1566=== RUN TestService_RequireScope_OIDC/ops_may_not_write1567=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1568=== RUN TestService_RequireScope_OIDC/reader_may_not_write1569=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1570=== RUN TestService_RequireScope_OIDC/static_token_may_admin1571=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1572=== RUN TestService_RequireScope_OIDC/static_token_may_write1573=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1574=== RUN TestService_RequireScope_OIDC/reader_may_read1575=== PAUSE TestService_RequireScope_OIDC/reader_may_read1576=== RUN TestService_RequireScope_OIDC/writer_implies_read1577=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1578=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1579=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1580=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1581=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1582=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1583=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1584=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1585=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1586=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1587=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1588=== CONT TestCacheConfigHandler/full_config,_no_issuer1589=== CONT TestCacheConfigHandler/no_signing_keys1590=== CONT TestCacheConfigHandler/no_cache_url_configured1591=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1592--- PASS: TestCacheConfigHandler (0.00s)1593 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1594 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1595 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1596 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1597=== CONT TestProxyWriteTimeout/narinfo1598=== CONT TestProxyWriteTimeout/10_GiB_nar1599=== CONT TestProxyWriteTimeout/unknown_size1600=== CONT TestProxyWriteTimeout/1_GiB_nar1601--- PASS: TestProxyWriteTimeout (0.00s)1602 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1603 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1604 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1605 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1606=== CONT TestService_RequireScope_OIDC/builder_may_write1607=== CONT TestService_RequireScope_OIDC/reader_may_read1608=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1609=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read16102026/10/04 19:46:18 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]1611=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1612=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1613=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1614=== CONT TestService_RequireScope_OIDC/writer_implies_read1615=== CONT TestService_RequireScope_OIDC/reader_may_not_write1616=== CONT TestService_RequireScope_OIDC/static_token_may_write1617=== CONT TestService_RequireScope_OIDC/static_token_may_admin1618=== CONT TestService_RequireScope_OIDC/ops_may_admin16192026/10/04 19:46:18 INFO Received complete push request method=POST path=/api/pushes/1/complete1620=== CONT TestService_RequireScope_OIDC/ops_may_not_write16212026/10/04 19:46:18 WARN Failed to register uploaded object key=cd10adhwsmjjzkpwz4anhk27mg0v3dbr.narinfo error="server returned 404: 404 page not found\n"16222026/10/04 19:46:18 WARN Failed to register uploaded object key=dl099iczm5nzal2kxkazcibzjxp2pzia.narinfo error="server returned 404: 404 page not found\n"1623=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1624--- PASS: TestService_RequireScope_OIDC (0.33s)1625 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1626 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1627 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1628 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1629 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1630 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1631 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1632 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1633 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1634 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1635 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1636 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1637 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1638 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)16392026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes16402026/10/04 19:46:18 INFO Upload complete. (58ms)16412026/10/04 19:46:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16422026/10/04 19:46:18 INFO Uploading wan1k6iac4f4v7zacbx0lzr3a558af0s-ca-test (144B)1643=== NAME TestClientSharedPathCommittedMidPush1644 client_integration_test.go:680: Retrieved narinfo from S3:1645 StorePath: /build/TestClientSharedPathCommittedMidPush3212674693/001/store/cd10adhwsmjjzkpwz4anhk27mg0v3dbr-shared-dep1646 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1647 Compression: zstd1648 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821649 NarSize: 1361650 References: 1651 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1652 client_integration_test.go:680: Retrieved narinfo from S3:1653 StorePath: /build/TestClientSharedPathCommittedMidPush3212674693/001/store/dl099iczm5nzal2kxkazcibzjxp2pzia-top1654 URL: nar/1qy7qznaa7c47d10b2l7gl5ry53la7r63lqymg0l2298744yvvda.nar.zst1655 Compression: zstd1656 NarHash: sha256:1qy7qznaa7c47d10b2l7gl5ry53la7r63lqymg0l2298744yvvda1657 NarSize: 2241658 References: /build/TestClientSharedPathCommittedMidPush3212674693/001/store/cd10adhwsmjjzkpwz4anhk27mg0v3dbr-shared-dep1659 CA: text:sha256:1s6blrgh2nam256jlch96fwjcak7lqhgc1av7w73vgf6v7l3lw9316602026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16612026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16622026/10/04 19:46:18 WARN Failed to register uploaded object key=log/38dw153p0fb3l9ifg5f7bk3bqc6hjwwy-ca-test.drv error="server returned 404: 404 page not found\n"16632026/10/04 19:46:18 INFO Received uploads request method=POST path=/api/pending_closures16642026/10/04 19:46:18 WARN Failed to register uploaded object key=wan1k6iac4f4v7zacbx0lzr3a558af0s.ls error="server returned 404: 404 page not found\n"16652026/10/04 19:46:18 INFO Signed narinfos id=1 count=116662026/10/04 19:46:18 INFO Uploading 1 narinfos1667--- PASS: TestClientSharedPathCommittedMidPush (0.48s)16682026/10/04 19:46:18 INFO Received complete push request method=POST path=/api/pushes/1/complete16692026/10/04 19:46:18 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/present16702026/10/04 19:46:18 WARN Failed to register uploaded object key=wan1k6iac4f4v7zacbx0lzr3a558af0s.narinfo error="server returned 404: 404 page not found\n"16712026/10/04 19:46:18 INFO Upload complete. (91ms)1672=== NAME TestClientCADerivations1673 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2362419643/001/store/wan1k6iac4f4v7zacbx0lzr3a558af0s-ca-test1674 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1675 Compression: zstd1676 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1677 NarSize: 1441678 References: 1679 Deriver: /build/TestClientCADerivations2362419643/001/store/38dw153p0fb3l9ifg5f7bk3bqc6hjwwy-ca-test.drv1680 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1681 client_ca_test.go:185: Checking for realisation files in S3...1682 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1683 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1684=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1685=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1686=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1687=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1688=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1689=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1690=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1691=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1692=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1693=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1694=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured16952026/10/04 19:46:18 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]1696=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16972026/10/04 19:46:18 WARN Authentication failed token_preview=eyJhbGciOi...m0x3frS9NA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1698--- PASS: TestService_AuthMiddleware_OIDC (0.33s)1699 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1700 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1701 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1702 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17032026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes17042026/10/04 19:46:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17052026/10/04 19:46:18 INFO Uploading as8sp4105mlkhfcij1ppvr5lygrpyjlr-test-script (136B)17062026/10/04 19:46:18 INFO Received uploads request method=POST path=/api/pending_closures17072026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17082026/10/04 19:46:18 WARN Failed to register uploaded object key=as8sp4105mlkhfcij1ppvr5lygrpyjlr.ls error="server returned 404: 404 page not found\n"17092026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17102026/10/04 19:46:18 WARN Failed to register uploaded object key=log/233fmiq2qw46l10jhxfa54kf7mbq2add-test-script.drv error="server returned 404: 404 page not found\n"17112026/10/04 19:46:18 INFO Signed narinfos id=1 count=117122026/10/04 19:46:18 INFO Uploading 1 narinfos17132026/10/04 19:46:18 INFO Received uploads request method=POST path=/api/pending_closures17142026/10/04 19:46:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17152026/10/04 19:46:18 INFO Uploading 6jqalzl1b62cpn8r0mhh0ywdb6yybhc6-shared-dep (136B)17162026/10/04 19:46:18 INFO Uploading 5fx9vqcnpwr2b70ri7miqq93jn8p0r2r-b (216B)17172026/10/04 19:46:18 INFO Received complete push request method=POST path=/api/pushes/1/complete17182026/10/04 19:46:18 WARN Failed to register uploaded object key=as8sp4105mlkhfcij1ppvr5lygrpyjlr.narinfo error="server returned 404: 404 page not found\n"17192026/10/04 19:46:18 INFO Received uploads request method=POST path=/api/pending_closures17202026/10/04 19:46:18 WARN Failed to register uploaded object key=vsb98ms66bmgv0mm5zzzw9ld81acgwdb.ls error="server returned 404: 404 page not found\n"17212026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17222026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17232026/10/04 19:46:18 WARN Failed to register uploaded object key=6jqalzl1b62cpn8r0mhh0ywdb6yybhc6.ls error="server returned 404: 404 page not found\n"17242026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/0dk4z2p8269mglpy43yciv872hwz10j27vslkh075azi6a231a1d.nar.zst error="server returned 404: 404 page not found\n"17252026/10/04 19:46:18 WARN Failed to register uploaded object key=5fx9vqcnpwr2b70ri7miqq93jn8p0r2r.ls error="server returned 404: 404 page not found\n"17262026/10/04 19:46:18 INFO Signed narinfos id=1 count=217272026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17282026/10/04 19:46:18 INFO Signed narinfos id=2 count=217292026/10/04 19:46:18 INFO Uploading 4 narinfos17302026/10/04 19:46:18 INFO Upload complete. (56ms)17312026/10/04 19:46:18 INFO Aborted multipart uploads count=0 kept=01732=== NAME TestClientWithDependencies1733 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2177042331/001/store) requires matching store prefix17342026/10/04 19:46:18 WARN Failed to register uploaded object key=6jqalzl1b62cpn8r0mhh0ywdb6yybhc6.narinfo error="server returned 404: 404 page not found\n"17352026/10/04 19:46:18 WARN Failed to register uploaded object key=vsb98ms66bmgv0mm5zzzw9ld81acgwdb.narinfo error="server returned 404: 404 page not found\n"17362026/10/04 19:46:18 WARN Failed to register uploaded object key=5fx9vqcnpwr2b70ri7miqq93jn8p0r2r.narinfo error="server returned 404: 404 page not found\n"17372026/10/04 19:46:18 WARN Force mode enabled - objects will be deleted immediately without grace period17382026/10/04 19:46:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17392026/10/04 19:46:18 WARN Failed to register uploaded object key=6jqalzl1b62cpn8r0mhh0ywdb6yybhc6.narinfo error="server returned 404: 404 page not found\n"1740--- PASS: TestClientWithDependencies (0.50s)1741=== NAME TestPinProtectsFromGC1742 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2624840319/001/store/3rhh4qzbxl6ny7b51207jci4pl29mgay-pinned-file.txt1743 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2624840319/001/store/pq4k00rki72dwyc7532v648wsvhllvdp-unpinned-file.txt17442026/10/04 19:46:18 INFO Completed upload id=117452026/10/04 19:46:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17462026/10/04 19:46:18 INFO Completed upload id=217472026/10/04 19:46:18 INFO Upload complete. (61ms)1748=== NAME TestClientFallsBackToClosures1749 client_pushes_test.go:112: Retrieved narinfo from S3:1750 StorePath: /build/TestClientFallsBackToClosures3487370242/001/store/6jqalzl1b62cpn8r0mhh0ywdb6yybhc6-shared-dep1751 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1752 Compression: zstd1753 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821754 NarSize: 1361755 References: 1756 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17572026/10/04 19:46:18 INFO Received uploads request method=POST path=/api/pending_closures17582026/10/04 19:46:18 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=01759 client_pushes_test.go:112: Retrieved narinfo from S3:1760 StorePath: /build/TestClientFallsBackToClosures3487370242/001/store/vsb98ms66bmgv0mm5zzzw9ld81acgwdb-a1761 URL: nar/0dk4z2p8269mglpy43yciv872hwz10j27vslkh075azi6a231a1d.nar.zst1762 Compression: zstd1763 NarHash: sha256:0dk4z2p8269mglpy43yciv872hwz10j27vslkh075azi6a231a1d1764 NarSize: 2161765 References: /build/TestClientFallsBackToClosures3487370242/001/store/6jqalzl1b62cpn8r0mhh0ywdb6yybhc6-shared-dep1766 CA: text:sha256:0ji2yca97gwa7n2xhid3higij2zsmk61zaf3nwnkj68hjsmyx03117672026/10/04 19:46:18 INFO Vacuumed table table=pending_closures17682026/10/04 19:46:18 INFO Vacuumed table table=pending_objects17692026/10/04 19:46:18 INFO Vacuumed table table=multipart_uploads17702026/10/04 19:46:18 INFO Vacuumed table table=closures1771 client_pushes_test.go:112: Retrieved narinfo from S3:1772 StorePath: /build/TestClientFallsBackToClosures3487370242/001/store/5fx9vqcnpwr2b70ri7miqq93jn8p0r2r-b1773 URL: nar/0dk4z2p8269mglpy43yciv872hwz10j27vslkh075azi6a231a1d.nar.zst1774 Compression: zstd1775 NarHash: sha256:0dk4z2p8269mglpy43yciv872hwz10j27vslkh075azi6a231a1d1776 NarSize: 2161777 References: /build/TestClientFallsBackToClosures3487370242/001/store/6jqalzl1b62cpn8r0mhh0ywdb6yybhc6-shared-dep1778 CA: text:sha256:0ji2yca97gwa7n2xhid3higij2zsmk61zaf3nwnkj68hjsmyx03117792026/10/04 19:46:18 INFO Vacuumed table table=objects1780--- PASS: TestClientFallsBackToClosures (0.49s)17812026/10/04 19:46:18 INFO Aborted multipart uploads count=0 kept=017822026/10/04 19:46:18 WARN Force mode enabled - objects will be deleted immediately without grace period17832026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes17842026/10/04 19:46:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017852026/10/04 19:46:18 INFO Vacuumed table table=pending_closures17862026/10/04 19:46:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17872026/10/04 19:46:18 INFO Vacuumed table table=pending_objects17882026/10/04 19:46:18 INFO Uploading swb0gbgz362ryfilnsmnpsqadn3v89y7-shared-dep (136B)17892026/10/04 19:46:18 INFO Uploading 5cjqjxpkpamhnw95mh18an337habrvb6-a (216B)17902026/10/04 19:46:18 INFO Vacuumed table table=multipart_uploads17912026/10/04 19:46:18 INFO Vacuumed table table=closures17922026/10/04 19:46:18 INFO Vacuumed table table=objects17932026/10/04 19:46:18 WARN Failed to register uploaded object key=znp0rcwgsrfbnikh229bjssyhyfy3jis.ls error="server returned 404: 404 page not found\n"17942026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17952026/10/04 19:46:18 WARN Failed to register uploaded object key=5cjqjxpkpamhnw95mh18an337habrvb6.ls error="server returned 404: 404 page not found\n"17962026/10/04 19:46:18 WARN Failed to register uploaded object key=swb0gbgz362ryfilnsmnpsqadn3v89y7.ls error="server returned 404: 404 page not found\n"17972026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/1q73rq7cp15li6gagylz5c69yypsrrd4v333xvci9fa11lj9p9a9.nar.zst error="server returned 404: 404 page not found\n"17982026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17992026/10/04 19:46:18 INFO Signed narinfos id=1 count=318002026/10/04 19:46:18 INFO Uploading 3 narinfos18012026/10/04 19:46:18 WARN Failed to register uploaded object key=znp0rcwgsrfbnikh229bjssyhyfy3jis.narinfo error="server returned 404: 404 page not found\n"18022026/10/04 19:46:18 WARN Failed to register uploaded object key=swb0gbgz362ryfilnsmnpsqadn3v89y7.narinfo error="server returned 404: 404 page not found\n"18032026/10/04 19:46:18 INFO Received complete push request method=POST path=/api/pushes/1/complete18042026/10/04 19:46:18 WARN Failed to register uploaded object key=5cjqjxpkpamhnw95mh18an337habrvb6.narinfo error="server returned 404: 404 page not found\n"1805--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1806 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.20s)1807 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.19s)18082026/10/04 19:46:18 INFO Upload complete. (55ms)1809=== NAME TestClientPushesUseOnePush1810 client_pushes_test.go:97: Retrieved narinfo from S3:1811 StorePath: /build/TestClientPushesUseOnePush3170851351/001/store/swb0gbgz362ryfilnsmnpsqadn3v89y7-shared-dep1812 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1813 Compression: zstd1814 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821815 NarSize: 1361816 References: 1817 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1818 client_pushes_test.go:97: Retrieved narinfo from S3:1819 StorePath: /build/TestClientPushesUseOnePush3170851351/001/store/5cjqjxpkpamhnw95mh18an337habrvb6-a1820 URL: nar/1q73rq7cp15li6gagylz5c69yypsrrd4v333xvci9fa11lj9p9a9.nar.zst1821 Compression: zstd1822 NarHash: sha256:1q73rq7cp15li6gagylz5c69yypsrrd4v333xvci9fa11lj9p9a91823 NarSize: 2161824 References: /build/TestClientPushesUseOnePush3170851351/001/store/swb0gbgz362ryfilnsmnpsqadn3v89y7-shared-dep1825 CA: text:sha256:149n08pw6yssjlybjmvpkvnnd1cna5qbh8hl1rxxbcyi6vjxy70n1826 client_pushes_test.go:97: Retrieved narinfo from S3:1827 StorePath: /build/TestClientPushesUseOnePush3170851351/001/store/znp0rcwgsrfbnikh229bjssyhyfy3jis-b1828 URL: nar/1q73rq7cp15li6gagylz5c69yypsrrd4v333xvci9fa11lj9p9a9.nar.zst1829 Compression: zstd1830 NarHash: sha256:1q73rq7cp15li6gagylz5c69yypsrrd4v333xvci9fa11lj9p9a91831 NarSize: 2161832 References: /build/TestClientPushesUseOnePush3170851351/001/store/swb0gbgz362ryfilnsmnpsqadn3v89y7-shared-dep1833 CA: text:sha256:149n08pw6yssjlybjmvpkvnnd1cna5qbh8hl1rxxbcyi6vjxy70n1834--- PASS: TestClientPushesUseOnePush (0.45s)18352026/10/04 19:46:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.25367ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1836=== NAME TestClientCADerivations1837 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1838 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1839 error: binary cache 's3://bucket71?endpoint=http://localhost:34485®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2362419643/001/store'1840 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11841--- PASS: TestClientCADerivations (0.64s)18422026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes1843--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.69s)18442026/10/04 19:46:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18452026/10/04 19:46:18 INFO Uploading 3rhh4qzbxl6ny7b51207jci4pl29mgay-pinned-file.txt (128B)18462026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18472026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18482026/10/04 19:46:18 WARN Failed to register uploaded object key=3rhh4qzbxl6ny7b51207jci4pl29mgay.ls error="server returned 404: 404 page not found\n"18492026/10/04 19:46:18 INFO Signed narinfos id=1 count=118502026/10/04 19:46:18 INFO Uploading 1 narinfos18512026/10/04 19:46:18 INFO Received complete push request method=POST path=/api/pushes/1/complete18522026/10/04 19:46:18 WARN Failed to register uploaded object key=3rhh4qzbxl6ny7b51207jci4pl29mgay.narinfo error="server returned 404: 404 page not found\n"18532026/10/04 19:46:18 INFO Upload complete. (48ms)18542026/10/04 19:46:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18552026/10/04 19:46:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18562026/10/04 19:46:18 INFO Received push request method=POST path=/api/pushes18572026/10/04 19:46:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18582026/10/04 19:46:18 INFO Uploading pq4k00rki72dwyc7532v648wsvhllvdp-unpinned-file.txt (128B)18592026/10/04 19:46:18 WARN Failed to register uploaded object key=pq4k00rki72dwyc7532v648wsvhllvdp.ls error="server returned 404: 404 page not found\n"18602026/10/04 19:46:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18612026/10/04 19:46:18 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18622026/10/04 19:46:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.214415ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18632026/10/04 19:46:18 INFO Signed narinfos id=2 count=118642026/10/04 19:46:18 INFO Uploading 1 narinfos18652026/10/04 19:46:18 INFO Received complete push request method=POST path=/api/pushes/2/complete18662026/10/04 19:46:18 WARN Failed to register uploaded object key=pq4k00rki72dwyc7532v648wsvhllvdp.narinfo error="server returned 404: 404 page not found\n"18672026/10/04 19:46:18 INFO Upload complete. (157ms)18682026/10/04 19:46:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures18692026/10/04 19:46:18 INFO Garbage collection started18702026/10/04 19:46:18 INFO Aborted multipart uploads count=0 kept=018712026/10/04 19:46:18 WARN Force mode enabled - objects will be deleted immediately without grace period18722026/10/04 19:46:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=018732026/10/04 19:46:18 INFO Vacuumed table table=pending_closures18742026/10/04 19:46:18 INFO Vacuumed table table=pending_objects18752026/10/04 19:46:18 INFO Vacuumed table table=multipart_uploads18762026/10/04 19:46:18 INFO Vacuumed table table=closures18772026/10/04 19:46:18 INFO Vacuumed table table=objects1878=== NAME TestOrphanedObjectsGCStressTest1879 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1880 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18812026/10/04 19:46:18 INFO lead: released remote=192.0.2.1:12341882--- PASS: TestLeadEndsOnShutdown (1.41s)1883=== NAME TestOrphanedObjectsGCStressTest1884 orphaned_objects_gc_test.go:509: Stress test completed successfully:1885 orphaned_objects_gc_test.go:510: - Active objects preserved: 201886 orphaned_objects_gc_test.go:511: - Objects deleted: 2101887 orphaned_objects_gc_test.go:512: - Total GC'd: 2101888--- PASS: TestOrphanedObjectsGCStressTest (2.05s)18892026/10/04 19:46:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=871.457277ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18902026/10/04 19:46:19 INFO lead: released remote=192.0.2.1:12341891--- PASS: TestPendingClosureWriteTimeout (0.00s)1892 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1893 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1894 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1895 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)1896--- PASS: TestUploadHandlersRejectOversizedBody (0.13s)1897 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)1898 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1899 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.02s)19002026/10/04 19:46:19 INFO lead: acquired remote=192.0.2.1:123419012026/10/04 19:46:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.58132045s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19022026/10/04 19:46:20 INFO lead: released remote=192.0.2.1:12341903--- PASS: TestLeadElectsOneAndHandsOver (2.64s)19042026/10/04 19:46:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01905=== NAME TestClientIntegration1906 client_integration_test.go:323: Objects in database after GC:1907 client_integration_test.go:323: Successfully deleted all objects with GC --force1908--- PASS: TestClientIntegration (2.50s)19092026/10/04 19:46:20 WARN Rate limiter enabled after throttle name=s3-test rate=519102026/10/04 19:46:20 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1911=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1912 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101913 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001914--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.09s)19152026/10/04 19:46:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019162026/10/04 19:46:20 INFO Received create pin request method=POST path=/api/pins/myapp19172026/10/04 19:46:20 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2624840319/001/store/3rhh4qzbxl6ny7b51207jci4pl29mgay-pinned-file.txt narinfo_key=3rhh4qzbxl6ny7b51207jci4pl29mgay.narinfo19182026/10/04 19:46:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures19192026/10/04 19:46:20 INFO Garbage collection started19202026/10/04 19:46:20 INFO Aborted multipart uploads count=0 kept=019212026/10/04 19:46:20 WARN Force mode enabled - objects will be deleted immediately without grace period19222026/10/04 19:46:20 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019232026/10/04 19:46:20 INFO Vacuumed table table=pending_closures19242026/10/04 19:46:20 INFO Vacuumed table table=pending_objects19252026/10/04 19:46:20 INFO Vacuumed table table=multipart_uploads19262026/10/04 19:46:20 INFO Vacuumed table table=closures19272026/10/04 19:46:20 INFO Vacuumed table table=objects1928--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.68s)19292026/10/04 19:46:21 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-config19302026/10/04 19:46:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.318386ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19312026/10/04 19:46:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.655683ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19322026/10/04 19:46:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.31288ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1933=== NAME TestPinProtectsFromGC1934 client_integration_test.go:840: Pin successfully protected closure from garbage collection1935--- PASS: TestPinProtectsFromGC (4.68s)1936--- PASS: TestConnectWaitsForAPeerMigration (5.12s)19372026/10/04 19:46:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.570036003s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19382026/10/04 19:46:23 INFO Aborted multipart uploads count=1 kept=019392026/10/04 19:46:23 INFO Received cleanup request method=DELETE path=/api/pending_closures19402026/10/04 19:46:23 INFO Aborted multipart uploads count=1 kept=01941--- PASS: TestPendingCleanupUsesOneCutoff (6.52s)19422026/10/04 19:46:24 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"19432026/10/04 19:46:24 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-config19442026/10/04 19:46:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.31012ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19452026/10/04 19:46:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=373.405584ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19462026/10/04 19:46:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=728.017648ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19472026/10/04 19:46:25 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.710438189s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19482026/10/04 19:46:27 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_closures19492026/10/04 19:46:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.003163ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19502026/10/04 19:46:27 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.507086ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19512026/10/04 19:46:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=731.057725ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19522026/10/04 19:46:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.64822981s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1953--- PASS: TestClientErrorHandling (0.00s)1954 --- PASS: TestClientErrorHandling/InvalidStorePath (0.19s)1955 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.22s)1956 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.60s)1957PASS19582026-10-04 19:46:31.011 UTC [129] LOG: received smart shutdown request19592026-10-04 19:46:31.015 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 119602026-10-04 19:46:31.025 UTC [134] LOG: shutting down19612026-10-04 19:46:31.026 UTC [134] LOG: checkpoint starting: shutdown immediate19622026-10-04 19:46:31.855 UTC [134] LOG: checkpoint complete: wrote 10745 buffers (65.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.185 s, sync=0.616 s, total=0.830 s; sync files=29992, longest=0.002 s, average=0.001 s; distance=414776 kB, estimate=414776 kB; lsn=0/1AC73E48, redo lsn=0/1AC73E4819632026-10-04 19:46:31.928 UTC [129] LOG: database system is shut down1964Running OIDC tests...1965=== RUN TestAudienceForIssuer1966=== PAUSE TestAudienceForIssuer1967=== RUN TestGlobMatch1968=== PAUSE TestGlobMatch1969=== RUN TestValidateToken_ValidToken1970=== PAUSE TestValidateToken_ValidToken1971=== RUN TestValidateToken_WrongAudience1972=== PAUSE TestValidateToken_WrongAudience1973=== RUN TestValidateToken_Expired1974=== PAUSE TestValidateToken_Expired1975=== RUN TestValidateToken_BoundClaimsMismatch1976=== PAUSE TestValidateToken_BoundClaimsMismatch1977=== RUN TestValidateToken_BoundSubjectMismatch1978=== PAUSE TestValidateToken_BoundSubjectMismatch1979=== RUN TestValidateToken_MultipleProviders1980=== PAUSE TestValidateToken_MultipleProviders1981=== RUN TestValidateToken_NoMatchingProvider1982=== PAUSE TestValidateToken_NoMatchingProvider1983=== RUN TestValidateToken_KubernetesServiceAccount1984=== PAUSE TestValidateToken_KubernetesServiceAccount1985=== RUN TestNewValidator_KubernetesRequiresCA1986=== PAUSE TestNewValidator_KubernetesRequiresCA1987=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1988=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1989=== RUN TestPins_ReservedForMatchingRule1990=== PAUSE TestPins_ReservedForMatchingRule1991=== RUN TestPins_TopLevelShorthand1992=== PAUSE TestPins_TopLevelShorthand1993=== RUN TestPins_ConfigValidation1994=== PAUSE TestPins_ConfigValidation1995=== RUN TestScopes_LegacyProviderDefaultsToWrite1996=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1997=== RUN TestScopes_Rules1998=== PAUSE TestScopes_Rules1999=== RUN TestScopes_ConfigValidation2000=== PAUSE TestScopes_ConfigValidation2001=== CONT TestAudienceForIssuer2002=== CONT TestPins_ConfigValidation2003--- PASS: TestAudienceForIssuer (0.00s)2004=== CONT TestValidateToken_NoMatchingProvider2005=== CONT TestPins_TopLevelShorthand2006=== CONT TestScopes_Rules2007=== CONT TestPins_ReservedForMatchingRule2008=== CONT TestScopes_ConfigValidation2009=== CONT TestValidateToken_Expired2010=== CONT TestGlobMatch2011=== CONT TestValidateToken_MultipleProviders2012=== RUN TestGlobMatch/foo_foo2013=== PAUSE TestGlobMatch/foo_foo2014=== RUN TestGlobMatch/foo_bar2015=== PAUSE TestGlobMatch/foo_bar2016=== RUN TestGlobMatch/*_2017=== PAUSE TestGlobMatch/*_2018=== RUN TestGlobMatch/*_anything2019=== PAUSE TestGlobMatch/*_anything2020=== CONT TestValidateToken_WrongAudience2021=== CONT TestValidateToken_KubernetesServiceAccount2022=== CONT TestScopes_LegacyProviderDefaultsToWrite2023=== CONT TestValidateToken_ValidToken2024=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2025=== RUN TestGlobMatch/foo*_foo2026=== PAUSE TestGlobMatch/foo*_foo2027=== RUN TestGlobMatch/foo*_foobar2028=== PAUSE TestGlobMatch/foo*_foobar2029=== CONT TestValidateToken_BoundSubjectMismatch2030=== CONT TestValidateToken_BoundClaimsMismatch2031=== CONT TestNewValidator_KubernetesRequiresCA2032--- PASS: TestPins_ConfigValidation (0.00s)2033=== RUN TestGlobMatch/foo*_bar2034=== PAUSE TestGlobMatch/foo*_bar2035=== RUN TestGlobMatch/*bar_bar2036=== PAUSE TestGlobMatch/*bar_bar2037=== RUN TestGlobMatch/*bar_foobar2038=== PAUSE TestGlobMatch/*bar_foobar2039=== RUN TestGlobMatch/*bar_foo2040=== PAUSE TestGlobMatch/*bar_foo2041=== RUN TestGlobMatch/foo*bar_foobar2042=== PAUSE TestGlobMatch/foo*bar_foobar2043=== RUN TestGlobMatch/foo*bar_foo123bar2044=== PAUSE TestGlobMatch/foo*bar_foo123bar2045=== RUN TestGlobMatch/foo*bar_foobarbaz2046=== PAUSE TestGlobMatch/foo*bar_foobarbaz2047=== RUN TestGlobMatch/*/*_foo/bar2048=== PAUSE TestGlobMatch/*/*_foo/bar2049=== RUN TestGlobMatch/*/*_foo2050=== PAUSE TestGlobMatch/*/*_foo2051--- PASS: TestScopes_ConfigValidation (0.00s)2052=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2053=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2054=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02055=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02056=== RUN TestGlobMatch/refs/*/main_refs/heads/main2057=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2058=== RUN TestGlobMatch/fo?_foo2059=== PAUSE TestGlobMatch/fo?_foo2060=== RUN TestGlobMatch/fo?_fo2061=== PAUSE TestGlobMatch/fo?_fo2062=== RUN TestGlobMatch/fo?_fooo2063=== PAUSE TestGlobMatch/fo?_fooo2064=== RUN TestGlobMatch/?oo_foo2065=== PAUSE TestGlobMatch/?oo_foo2066=== RUN TestGlobMatch/?oo_boo2067=== PAUSE TestGlobMatch/?oo_boo2068=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2069=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2070=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2071=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2072=== CONT TestGlobMatch/foo_foo2073=== CONT TestGlobMatch/fo?_fo2074=== CONT TestGlobMatch/*_2075=== CONT TestGlobMatch/foo*_bar2076=== CONT TestGlobMatch/foo*bar_foobar2077=== CONT TestGlobMatch/foo*_foobar2078=== CONT TestGlobMatch/foo*_foo2079=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02080=== CONT TestGlobMatch/fo?_foo2081=== CONT TestGlobMatch/refs/*/main_refs/heads/main2082=== CONT TestGlobMatch/*bar_foobar2083=== CONT TestGlobMatch/*bar_bar2084=== CONT TestGlobMatch/*/*_foo2085=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2086=== CONT TestGlobMatch/*/*_foo/bar2087=== CONT TestGlobMatch/foo*bar_foo123bar2088=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2089=== CONT TestGlobMatch/?oo_boo2090=== CONT TestGlobMatch/?oo_foo2091=== CONT TestGlobMatch/fo?_fooo2092=== CONT TestGlobMatch/foo_bar2093=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2094=== CONT TestGlobMatch/*bar_foo2095=== CONT TestGlobMatch/foo*bar_foobarbaz2096=== CONT TestGlobMatch/*_anything2097--- PASS: TestGlobMatch (0.00s)2098 --- PASS: TestGlobMatch/foo_foo (0.00s)2099 --- PASS: TestGlobMatch/fo?_fo (0.00s)2100 --- PASS: TestGlobMatch/*_ (0.00s)2101 --- PASS: TestGlobMatch/foo*_bar (0.00s)2102 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2103 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2104 --- PASS: TestGlobMatch/foo*_foo (0.00s)2105 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2106 --- PASS: TestGlobMatch/fo?_foo (0.00s)2107 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2108 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2109 --- PASS: TestGlobMatch/*bar_bar (0.00s)2110 --- PASS: TestGlobMatch/*/*_foo (0.00s)2111 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2112 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2113 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2114 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2115 --- PASS: TestGlobMatch/?oo_boo (0.00s)2116 --- PASS: TestGlobMatch/?oo_foo (0.00s)2117 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2118 --- PASS: TestGlobMatch/foo_bar (0.00s)2119 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2120 --- PASS: TestGlobMatch/*bar_foo (0.00s)2121 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2122 --- PASS: TestGlobMatch/*_anything (0.00s)21232026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45913/oidc21242026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36679/oidc2125--- PASS: TestValidateToken_WrongAudience (0.04s)2126--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)21272026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46499/oidc2128--- PASS: TestScopes_Rules (0.09s)21292026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34389/oidc2130--- PASS: TestPins_TopLevelShorthand (0.09s)21312026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44021/oidc2132--- PASS: TestValidateToken_ValidToken (0.10s)21332026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44577/oidc21342026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33625/oidc2135--- PASS: TestValidateToken_Expired (0.13s)2136--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)21372026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44611/oidc2138--- PASS: TestValidateToken_BoundClaimsMismatch (0.19s)21392026/10/04 19:46:33 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321402026/10/04 19:46:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34909/oidc21412026/10/04 19:46:33 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:436132142--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.20s)2143--- PASS: TestPins_ReservedForMatchingRule (0.20s)2144--- PASS: TestValidateToken_KubernetesServiceAccount (0.20s)21452026/10/04 19:46:33 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34591/oidc2146--- PASS: TestValidateToken_NoMatchingProvider (0.28s)21472026/10/04 19:46:33 http: TLS handshake error from 127.0.0.1:46964: remote error: tls: bad certificate2148--- PASS: TestNewValidator_KubernetesRequiresCA (0.28s)21492026/10/04 19:46:33 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41703/oidc21502026/10/04 19:46:33 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40853/oidc2151--- PASS: TestValidateToken_MultipleProviders (0.46s)2152PASS2153Running hook tests...2154=== RUN TestSendPathsEmpty2155=== PAUSE TestSendPathsEmpty2156=== RUN TestQueueEnqueueAndFetch2157=== PAUSE TestQueueEnqueueAndFetch2158=== RUN TestQueueDeduplication2159=== PAUSE TestQueueDeduplication2160=== RUN TestQueueRemove2161=== PAUSE TestQueueRemove2162=== RUN TestQueueFetchBatchLimit2163=== PAUSE TestQueueFetchBatchLimit2164=== RUN TestQueueRetryMovesToBack2165=== PAUSE TestQueueRetryMovesToBack2166=== RUN TestQueueFetchRemoveLifecycle2167=== PAUSE TestQueueFetchRemoveLifecycle2168=== RUN TestQueueConcurrentWriters2169=== PAUSE TestQueueConcurrentWriters2170=== RUN TestQueueRemoveLargeClosure2171=== PAUSE TestQueueRemoveLargeClosure2172=== RUN TestServerClientIntegration2173=== PAUSE TestServerClientIntegration2174=== RUN TestServerQueueError2175=== PAUSE TestServerQueueError2176=== RUN TestGetListenerSocketActivation2177 server_test.go:210: === RUN TestGetListenerSocketActivation2178 --- PASS: TestGetListenerSocketActivation (0.00s)2179 PASS2180 2181--- PASS: TestGetListenerSocketActivation (0.01s)2182=== RUN TestDrainIsolatesPoisonPath2183=== PAUSE TestDrainIsolatesPoisonPath2184=== RUN TestRunNotBlockedByPoisonHead2185=== PAUSE TestRunNotBlockedByPoisonHead2186=== RUN TestDrainGivesUpWhenServerDown2187=== PAUSE TestDrainGivesUpWhenServerDown2188=== RUN TestFailedPathPrunedByLaterClosure2189=== PAUSE TestFailedPathPrunedByLaterClosure2190=== RUN TestWorkerUploadsAndRemoves2191=== PAUSE TestWorkerUploadsAndRemoves2192=== RUN TestWorkerSkipsGCdPaths2193=== PAUSE TestWorkerSkipsGCdPaths2194=== RUN TestWorkerPrunesClosureDeps2195=== PAUSE TestWorkerPrunesClosureDeps2196=== RUN TestDrainTimeout2197=== PAUSE TestDrainTimeout2198=== CONT TestSendPathsEmpty2199=== CONT TestDrainGivesUpWhenServerDown2200=== CONT TestWorkerSkipsGCdPaths2201--- PASS: TestSendPathsEmpty (0.00s)2202=== CONT TestQueueConcurrentWriters2203=== CONT TestQueueFetchRemoveLifecycle2204=== CONT TestRunNotBlockedByPoisonHead2205=== CONT TestQueueRetryMovesToBack2206=== CONT TestDrainIsolatesPoisonPath2207=== CONT TestServerQueueError2208=== CONT TestQueueFetchBatchLimit2209=== CONT TestServerClientIntegration2210=== CONT TestQueueRemove2211=== CONT TestQueueDeduplication2212=== CONT TestQueueRemoveLargeClosure2213=== CONT TestQueueEnqueueAndFetch2214=== CONT TestWorkerUploadsAndRemoves2215=== CONT TestFailedPathPrunedByLaterClosure2216=== CONT TestDrainTimeout22172026/10/04 19:46:33 ERROR Failed to queue paths error="permission denied" count=12218=== CONT TestWorkerPrunesClosureDeps2219--- PASS: TestServerClientIntegration (0.00s)2220--- PASS: TestServerQueueError (0.00s)22212026/10/04 19:46:33 INFO Uploading batch count=422222026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=422232026/10/04 19:46:33 INFO Uploading batch count=222242026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=222252026/10/04 19:46:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1137937717/002/a22262026/10/04 19:46:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2691066500/002/bbb22272026/10/04 19:46:33 INFO Upload queue status pending=22228--- PASS: TestQueueFetchBatchLimit (0.01s)22292026/10/04 19:46:33 INFO Upload queue status pending=322302026/10/04 19:46:33 INFO Uploading batch count=122312026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=122322026/10/04 19:46:33 INFO Uploading batch count=222332026/10/04 19:46:33 INFO Uploading batch count=122342026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=122352026/10/04 19:46:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1137937717/002/b22362026/10/04 19:46:33 INFO Uploading batch count=22237--- PASS: TestQueueRetryMovesToBack (0.01s)22382026/10/04 19:46:33 INFO Upload queue status pending=222392026/10/04 19:46:33 INFO Upload queue status pending=222402026/10/04 19:46:33 INFO Uploading batch count=122412026/10/04 19:46:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3322615924/002/nonexistent2242--- PASS: TestQueueDeduplication (0.01s)22432026/10/04 19:46:33 INFO Uploading batch count=222442026/10/04 19:46:33 INFO Uploading batch count=122452026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=22246--- PASS: TestQueueRemove (0.01s)22472026/10/04 19:46:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1137937717/002/c22482026/10/04 19:46:33 INFO Uploading batch count=122492026/10/04 19:46:33 INFO Uploading batch count=122502026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=122512026/10/04 19:46:33 INFO Uploading batch count=122522026/10/04 19:46:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1137937717/002/d2253--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2254--- PASS: TestQueueEnqueueAndFetch (0.01s)22552026/10/04 19:46:33 INFO Uploading batch count=122562026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=122572026/10/04 19:46:33 INFO Uploading batch count=222582026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=222592026/10/04 19:46:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1137937717/002/e22602026/10/04 19:46:33 INFO Uploading batch count=122612026/10/04 19:46:33 ERROR Upload failed error="upload failed" count=122622026/10/04 19:46:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1137937717/002/f22632026/10/04 19:46:33 ERROR Drain finished with paths left in queue remaining=1022642026/10/04 19:46:33 ERROR Drain finished with paths left in queue remaining=12265--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2266--- PASS: TestDrainIsolatesPoisonPath (0.02s)2267--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2268--- PASS: TestWorkerSkipsGCdPaths (0.03s)2269--- PASS: TestWorkerUploadsAndRemoves (0.03s)2270--- PASS: TestWorkerPrunesClosureDeps (0.03s)2271--- PASS: TestQueueRemoveLargeClosure (0.10s)2272--- PASS: TestQueueConcurrentWriters (0.15s)22732026/10/04 19:46:34 ERROR Upload failed error="context deadline exceeded" count=222742026/10/04 19:46:34 ERROR Drain finished with paths left in queue remaining=42275--- PASS: TestDrainTimeout (0.21s)22762026/10/04 19:46:34 INFO Uploading batch count=122772026/10/04 19:46:34 INFO Uploading batch count=122782026/10/04 19:46:34 INFO Uploading batch count=122792026/10/04 19:46:34 ERROR Upload failed error="upload failed" count=122802026/10/04 19:46:34 INFO Uploading batch count=122812026/10/04 19:46:34 ERROR Upload failed error="upload failed" count=122822026/10/04 19:46:34 INFO Uploading batch count=122832026/10/04 19:46:34 ERROR Upload failed error="upload failed" count=122842026/10/04 19:46:34 INFO Uploading batch count=122852026/10/04 19:46:34 ERROR Upload failed error="upload failed" count=122862026/10/04 19:46:34 ERROR Drain finished with paths left in queue remaining=12287--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2288PASS