niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #349
· 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.09s)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 TestEncodeNixBase32WithRealHash97=== CONT TestScriptTokenScriptFails98=== CONT TestDoWithRetry_BodyReplayedViaGetBody99=== CONT TestScriptTokenEmptyCommand100=== CONT TestSetClientTLS101=== CONT TestScriptTokenBadJSON102=== CONT TestUploadMultipart_SupersededByPeer103=== RUN TestUploadMultipart_SupersededByPeer/exists104=== PAUSE TestUploadMultipart_SupersededByPeer/exists105=== RUN TestUploadMultipart_SupersededByPeer/missing106=== PAUSE TestUploadMultipart_SupersededByPeer/missing107=== CONT TestScriptTokenEmptyToken108=== CONT TestDumpPathSingleFile109=== CONT TestClientSignaturesByStorePath110=== CONT TestScriptTokenCachesUntilRefresh111=== CONT TestDumpPathMatchesNix112=== CONT TestScriptTokenNoExpiryRerunsEveryCall113=== CONT TestEncodeNixBase32114=== CONT TestFileTokenEmpty115=== CONT TestFileTokenMissing116=== CONT TestStreamPushReportsSignatures117=== CONT TestStreamPushRequestLine118=== CONT TestFileTokenReadsAndCaches119=== CONT TestStreamPushGivesUpOnDeadServer120=== CONT TestStaticToken121=== CONT TestStreamPushIsolatesFailures122=== CONT TestSetClientTLSErrors123=== CONT TestStreamPushBatchesUnderLoad124=== CONT TestSetClientTLSDoesNotMutateDefaultTransport125--- PASS: TestEncodeNixBase32WithRealHash (0.00s)126=== CONT TestStreamPushReportsEveryPath127=== CONT TestShellSplitErrors128=== CONT TestFilterOversizedClosures129=== CONT TestShellSplit130=== CONT TestPartSizeForNAR131=== RUN TestPartSizeForNAR/zero_stays_at_minimum132=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum133=== RUN TestPartSizeForNAR/small_stays_at_minimum134=== RUN TestFilterOversizedClosures/no_limit_keeps_everything135--- PASS: TestScriptTokenEmptyCommand (0.00s)136--- PASS: TestScriptTokenScriptFails (0.00s)137--- PASS: TestClientSignaturesByStorePath (0.00s)138=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything139=== PAUSE TestPartSizeForNAR/small_stays_at_minimum140=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum1412026/10/04 19:28:49 ERROR Upload failed error="bad path" count=3142=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum1432026/10/04 19:28:49 WARN Rate limiter enabled after throttle name=server-test rate=5144=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts145=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts1462026/10/04 19:28:49 ERROR Upload failed error="connection refused" count=20147=== RUN TestPartSizeForNAR/1_TiB1482026/10/04 19:28:49 ERROR Server seems unavailable, giving up on batch untried=17149=== CONT TestParsePathInfoJSONMultiplePaths150=== PAUSE TestPartSizeForNAR/1_TiB1512026/10/04 19:28:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42339152=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1532026/10/04 19:28:49 ERROR Upload failed error=boom count=11542026/10/04 19:28:49 ERROR Upload failed error=boom count=1155=== CONT TestRegisterUploadedObjectReusesConnections156=== CONT TestPathInfoHashCompatibility157=== RUN TestEncodeNixBase32/test_string_hash158--- PASS: TestShellSplitErrors (0.00s)159=== CONT TestRateLimiterFeedback160=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped161=== CONT TestUploadMultipart_PartsInParallel162=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess163=== CONT TestCaseHackSuffix164=== RUN TestPartSizeForNAR/5_TiB_S3_max_object165=== CONT TestResolveStorePath166=== CONT TestParsePathInfoJSON167=== CONT TestGetStorePathHash168=== RUN TestSetClientTLSErrors/missing_cert_file169=== CONT TestConvertHashToNix32170=== CONT TestPathInfoCACompatibility171=== RUN TestPathInfoCACompatibility/null_ca_field1722026/10/04 19:28:49 WARN Rate limiter backed off name=server-test rate=5173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1752026/10/04 19:28:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42339176=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)177=== PAUSE TestEncodeNixBase32/test_string_hash178--- PASS: TestShellSplit (0.00s)179=== RUN TestSetClientTLS/rejects_connection_without_client_cert1802026/10/04 19:28:49 WARN Rate limiter enabled after throttle name=server-test rate=5181=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped182=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object183--- PASS: TestFileTokenMissing (0.00s)184=== RUN TestRateLimiterFeedback/429_enables_limiter185=== PAUSE TestRateLimiterFeedback/429_enables_limiter186=== CONT TestDumpPathWriterError187=== PAUSE TestPathInfoCACompatibility/null_ca_field188=== RUN TestPathInfoCACompatibility/old_string_format_-_text189=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text190=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive192=== RUN TestPathInfoCACompatibility/new_structured_format_-_text193=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text194=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method195=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method196=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert197=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== RUN TestEncodeNixBase32/empty_input199=== RUN TestGetStorePathHash/valid_store_path200=== RUN TestParsePathInfoJSON/Nix_format201=== RUN TestFilterOversizedClosures/all_closures_skipped202=== PAUSE TestSetClientTLSErrors/missing_cert_file203=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32204=== CONT TestUploadMultipart_SupersededByPeer/missing205=== CONT TestUploadMultipart_SupersededByPeer/exists206=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)207=== RUN TestPartSizeForNAR/capped_at_5_GiB208=== PAUSE TestPartSizeForNAR/capped_at_5_GiB209=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA210=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA211=== RUN TestSetClientTLS/preserves_debug_logging_transport212=== PAUSE TestSetClientTLS/preserves_debug_logging_transport213=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths214--- PASS: TestStaticToken (0.00s)215--- PASS: TestStreamPushReportsEveryPath (0.00s)216--- PASS: TestStreamPushIsolatesFailures (0.00s)217--- PASS: TestFileTokenReadsAndCaches (0.00s)218--- PASS: TestDoServerRequestAttachesToken (0.01s)219=== RUN TestConvertHashToNix32/already_Nix32_format220=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon221=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon222=== PAUSE TestParsePathInfoJSON/Nix_format223=== RUN TestParsePathInfoJSON/Lix_format224=== PAUSE TestParsePathInfoJSON/Lix_format225=== RUN TestParsePathInfoJSON/empty_input226=== RUN TestSetClientTLSErrors/missing_key_file227=== RUN TestRateLimiterFeedback/503_enables_limiter228=== PAUSE TestRateLimiterFeedback/503_enables_limiter229=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter230=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter231=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter232=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI233=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI234=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512235=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512236=== CONT TestPathInfoCACompatibility/null_ca_field237=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths238=== CONT TestSetClientTLS/rejects_connection_without_client_cert239=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method240=== CONT TestPartSizeForNAR/capped_at_5_GiB241=== CONT TestPartSizeForNAR/5_TiB_S3_max_object242=== CONT TestPartSizeForNAR/1_TiB243=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts244=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum245=== CONT TestPartSizeForNAR/small_stays_at_minimum246=== CONT TestSetClientTLS/preserves_debug_logging_transport247=== PAUSE TestConvertHashToNix32/already_Nix32_format248=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA249=== CONT TestPathInfoCACompatibility/new_structured_format_-_text250=== CONT TestPathInfoCACompatibility/old_string_format_-_text251=== CONT TestPartSizeForNAR/zero_stays_at_minimum252=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI253=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512254=== PAUSE TestGetStorePathHash/valid_store_path255=== RUN TestGetStorePathHash/basename_without_hyphen_should_error256=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error257=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error258=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error259=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== CONT TestGetStorePathHash/valid_store_path262=== PAUSE TestFilterOversizedClosures/all_closures_skipped263=== CONT TestFilterOversizedClosures/no_limit_keeps_everything264=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error265=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error266=== CONT TestGetStorePathHash/basename_without_hyphen_should_error267=== PAUSE TestParsePathInfoJSON/empty_input268=== RUN TestParsePathInfoJSON/whitespace_only269=== PAUSE TestParsePathInfoJSON/whitespace_only270=== RUN TestParsePathInfoJSON/invalid_JSON271=== PAUSE TestParsePathInfoJSON/invalid_JSON272=== CONT TestParsePathInfoJSON/Nix_format273=== CONT TestFilterOversizedClosures/all_closures_skipped2742026/10/04 19:28:49 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50275=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2762026/10/04 19:28:49 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=2000277=== PAUSE TestSetClientTLSErrors/missing_key_file278=== RUN TestSetClientTLSErrors/missing_ca_file279=== PAUSE TestSetClientTLSErrors/missing_ca_file280=== RUN TestSetClientTLSErrors/invalid_ca_file281=== PAUSE TestSetClientTLSErrors/invalid_ca_file282=== CONT TestSetClientTLSErrors/missing_cert_file283=== CONT TestParsePathInfoJSON/invalid_JSON284=== CONT TestParsePathInfoJSON/whitespace_only285=== CONT TestParsePathInfoJSON/empty_input286=== CONT TestParsePathInfoJSON/Lix_format287--- PASS: TestScriptTokenBadJSON (0.01s)288--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)289--- PASS: TestFileTokenEmpty (0.00s)290--- PASS: TestStreamPushReportsSignatures (0.00s)291--- PASS: TestScriptTokenEmptyToken (0.01s)292--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)293--- PASS: TestResolveStorePath (0.00s)294--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)295--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)296--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)297--- PASS: TestDumpPathSingleFile (0.03s)298=== CONT TestSetClientTLSErrors/invalid_ca_file299=== CONT TestSetClientTLSErrors/missing_ca_file300=== CONT TestSetClientTLSErrors/missing_key_file301=== RUN TestConvertHashToNix32/invalid_format302=== PAUSE TestConvertHashToNix32/invalid_format303=== CONT TestConvertHashToNix32/SRI_format_to_Nix32304=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths305--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)306 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)307 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)308=== CONT TestConvertHashToNix32/invalid_format309=== CONT TestConvertHashToNix32/already_Nix32_format310--- PASS: TestConvertHashToNix32 (0.03s)311 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)312 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)313 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)314=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive315--- PASS: TestPartSizeForNAR (0.03s)316 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)317 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)318 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)319 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)320 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)321 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)322 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)323--- PASS: TestPathInfoCACompatibility (0.03s)324 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)325 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)326 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)327 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)328 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)329=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)330=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter331=== PAUSE TestEncodeNixBase32/empty_input332=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon333=== CONT TestRateLimiterFeedback/429_enables_limiter334=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter335=== CONT TestRateLimiterFeedback/503_enables_limiter336=== CONT TestEncodeNixBase32/test_string_hash337=== CONT TestEncodeNixBase32/empty_input338=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3392026/10/04 19:28:49 WARN Rate limiter enabled after throttle name=server-test rate=53402026/10/04 19:28:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33943341--- PASS: TestGetStorePathHash (0.03s)342 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)343 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)345 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)346--- PASS: TestFilterOversizedClosures (0.04s)347 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)348 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)349 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)350--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)351 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)352 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)353--- PASS: TestParsePathInfoJSON (0.00s)354 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)355 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)356 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)357 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)358 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)359--- PASS: TestPathInfoHashCompatibility (0.03s)360 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)361 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)362 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)363 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)3642026/10/04 19:28:49 WARN Rate limiter enabled after throttle name=server-test rate=5365--- PASS: TestEncodeNixBase32 (0.03s)366 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)367 --- PASS: TestEncodeNixBase32/empty_input (0.00s)3682026/10/04 19:28:49 WARN Rate limiter backed off name=server-test rate=53692026/10/04 19:28:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:46499370--- PASS: TestSetClientTLSErrors (0.04s)371 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)372 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)374 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3752026/10/04 19:28:49 WARN Rate limiter backed off name=server-test rate=5376--- PASS: TestRateLimiterFeedback (0.03s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)380 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3812026/10/04 19:28:49 http: TLS handshake error from 127.0.0.1:60776: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.04s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)387--- PASS: TestStreamPushRequestLine (0.05s)388--- PASS: TestDumpPathWriterError (0.02s)389--- PASS: TestCaseHackSuffix (0.06s)390--- PASS: TestDumpPathMatchesNix (0.09s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)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/postgres3982894900/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/postgres3982894900/data -l logfile start422423/build/postgres3982894900:5432 - no response4242026-10-04 19:28:51.103 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-04 19:28:51.103 UTC [128] LOG: listening on Unix socket "/build/postgres3982894900/.s.PGSQL.5432"4262026-10-04 19:28:51.107 UTC [135] LOG: database system was shut down at 2026-10-04 19:28:50 UTC4272026-10-04 19:28:51.111 UTC [128] LOG: database system is ready to accept connections428/build/postgres3982894900:5432 - accepting connections429{"timestamp":"2026-10-04T19:28:51.304040042Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3a55d861-a7b5-4a83-89de-0d61afd692c8","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(208)"}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:28:51 INFO lead: acquired remote=192.0.2.1:12344762026/10/04 19:28:52 INFO lead: released remote=192.0.2.1:12344772026/10/04 19:28:52 INFO lead: acquired remote=192.0.2.1:12344782026/10/04 19:28:53 INFO lead: released remote=192.0.2.1:1234479--- PASS: TestLeadIncumbentWinsAfterRestart (2.29s)480=== RUN TestLeadEndsOnShutdown481=== PAUSE TestLeadEndsOnShutdown482=== RUN TestLeadEndsWhenItsConnectionHangs4832026/10/04 19:28:53 INFO lead: acquired remote=192.0.2.1:12344842026-10-04 19:28:55.200 UTC [384] FATAL: terminating connection due to administrator command4852026/10/04 19:28:55 INFO lead: acquired remote=192.0.2.1:12344862026/10/04 19:28:56 WARN lead: lock connection lost error="timeout: context deadline exceeded"4872026/10/04 19:28:56 INFO lead: released remote=192.0.2.1:12344882026/10/04 19:28:56 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:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/04 19:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/04 19:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/04 19:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/04 19:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/04 19:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/04 19:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/04 19:28:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/04 19:28:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/04 19:28:57 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 TestPresignedUploadRegisteredBeforeCommit677=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT678=== CONT TestPush_RejectsBadRequests679=== CONT TestService_AuthMiddleware680=== CONT TestCompletedNarNotReofferedAcrossClosures681=== CONT TestRedundantMultipartUpload682=== CONT TestPush_SignsNarinfosOfItsPendingObjects683=== CONT TestUploadHandlersRejectInvalidKeys684=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit685=== CONT TestPush_CompleteCommitsEveryRoot686=== CONT TestPush_OverlappingRootsStoreOneRowPerKey687=== CONT TestReadRedirectUsesPublicS3URL688=== CONT TestReadProxyRangeRequest689=== CONT TestReadRedirectKeepsNarinfoProxied690=== CONT TestGCEndsOnShutdown691=== CONT TestCommitRacingPendingCleanupKeepsObjects692=== CONT TestPushWaitsForSweepHoldingRow693=== CONT TestSweepRechecksPendingAfterLocking694=== CONT TestGetExistingObjectsLocksRows695=== CONT TestRegisterCompletedObjectNeedsPendingRow696=== CONT TestFailedS3DeleteKeepsTombstone697=== CONT TestForceGCDuringPushOffersSweptObject698=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows699=== CONT TestGCTaskStore_StartNew700=== CONT TestCompleteMultipartUpload_ErrorButObjectExists701=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info702=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows703=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check704=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check705--- PASS: TestGCTaskStore_StartNew (0.00s)706=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info707=== CONT TestGCSweepDeliversEachKeyOnce708=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection709=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal710=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal711=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key712=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key713=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key714=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key715=== CONT TestSweepSkipsRowsLockedByPush7162026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures717--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.28s)718=== CONT TestTombstonedObjectOfferedWithoutWaiting7192026/10/04 19:28:57 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"720--- PASS: TestService_AuthMiddleware (0.29s)721=== CONT TestReadRedirectNar7222026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures723=== RUN TestPush_RejectsBadRequests/no_roots724=== PAUSE TestPush_RejectsBadRequests/no_roots725=== RUN TestPush_RejectsBadRequests/no_objects726=== PAUSE TestPush_RejectsBadRequests/no_objects727=== RUN TestPush_RejectsBadRequests/bad_root728=== PAUSE TestPush_RejectsBadRequests/bad_root729=== RUN TestPush_RejectsBadRequests/root_not_in_objects730=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects731=== CONT TestGCSweepSkipsPendingObjects7322026/10/04 19:28:57 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7332026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures734--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.32s)735=== CONT TestDeduplicatedObjectsRecordedAsPending736--- PASS: TestReadProxyRangeRequest (0.34s)737=== CONT TestReadProxyDisabled7382026/10/04 19:28:57 INFO Received push request method=POST path=/api/pushes7392026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=07402026/10/04 19:28:57 INFO Received complete push request method=POST path=/api/pushes/1/complete7412026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period7422026/10/04 19:28:57 INFO Received push request method=POST path=/api/pushes7432026/10/04 19:28:57 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=07442026/10/04 19:28:57 INFO Received push request method=POST path=/api/pushes7452026/10/04 19:28:57 INFO Vacuumed table table=pending_closures7462026/10/04 19:28:57 INFO Vacuumed table table=pending_objects7472026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads7482026/10/04 19:28:57 INFO Vacuumed table table=closures7492026/10/04 19:28:57 INFO Vacuumed table table=objects7502026/10/04 19:28:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7512026/10/04 19:28:57 INFO Signed narinfos id=1 count=17522026/10/04 19:28:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7532026/10/04 19:28:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7542026/10/04 19:28:57 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"7552026/10/04 19:28:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7562026/10/04 19:28:57 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"7572026/10/04 19:28:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7582026/10/04 19:28:57 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=17592026/10/04 19:28:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7602026/10/04 19:28:57 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo761--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.41s)762=== CONT TestPushDedupSurvivesConcurrentGC763--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.41s)764=== CONT TestReadProxyRootRedirectsToIndexHTML765--- PASS: TestReadRedirectUsesPublicS3URL (0.42s)766=== CONT TestGCMetrics767--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.43s)768=== CONT TestReadProxyConditionalGet7692026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=07702026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period7712026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures772--- PASS: TestReadRedirectKeepsNarinfoProxied (0.47s)773=== CONT TestGCBugBareHashReferences7742026/10/04 19:28:57 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=07752026/10/04 19:28:57 INFO Vacuumed table table=pending_closures7762026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures7772026/10/04 19:28:57 INFO Vacuumed table table=pending_objects7782026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads7792026/10/04 19:28:57 INFO Vacuumed table table=closures7802026/10/04 19:28:57 INFO Vacuumed table table=objects7812026/10/04 19:28:57 INFO Received complete push request method=POST path=/api/pushes/2/complete7822026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures783--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.49s)784=== CONT TestReadProxyOutlastsServerWriteTimeout7852026/10/04 19:28:57 INFO Received push request method=POST path=/api/pushes7862026/10/04 19:28:57 INFO Received complete push request method=POST path=/api/pushes/1/complete7872026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures788--- PASS: TestPush_CompleteCommitsEveryRoot (0.53s)789=== CONT TestGCAdvisoryLockBlocksConcurrentRun7902026/10/04 19:28:57 INFO Received push request method=POST path=/api/pushes791--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.56s)792=== CONT TestReadProxyHead7932026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures7942026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=07952026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=07962026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period7972026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period7982026/10/04 19:28:57 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=07992026/10/04 19:28:57 INFO Vacuumed table table=pending_closures8002026/10/04 19:28:57 INFO Vacuumed table table=pending_objects8012026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads8022026/10/04 19:28:57 INFO Vacuumed table table=closures803--- PASS: TestGetExistingObjectsLocksRows (0.61s)804=== CONT TestReadProxyInvalidPath8052026/10/04 19:28:57 INFO Vacuumed table table=objects8062026/10/04 19:28:57 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8072026/10/04 19:28:57 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."808--- PASS: TestFailedS3DeleteKeepsTombstone (0.62s)809=== CONT TestLeadEndsOnShutdown8102026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=08112026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period8122026/10/04 19:28:57 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=08132026/10/04 19:28:57 INFO Vacuumed table table=pending_closures8142026/10/04 19:28:57 INFO Vacuumed table table=pending_objects8152026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads8162026/10/04 19:28:57 INFO Vacuumed table table=closures8172026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=08182026/10/04 19:28:57 INFO Vacuumed table table=objects8192026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period820--- PASS: TestSweepSkipsRowsLockedByPush (0.64s)821=== CONT TestReadProxy4048222026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures8232026/10/04 19:28:57 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=08242026/10/04 19:28:57 INFO Vacuumed table table=pending_closures8252026/10/04 19:28:57 INFO Vacuumed table table=pending_objects8262026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads8272026/10/04 19:28:57 INFO Vacuumed table table=closures8282026/10/04 19:28:57 INFO Vacuumed table table=objects829--- PASS: TestSweepRechecksPendingAfterLocking (0.66s)830=== CONT TestLeadElectsOneAndHandsOver8312026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures8322026/10/04 19:28:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete833--- PASS: TestGCEndsOnShutdown (0.69s)834=== CONT TestReadProxyNarStreaming8352026/10/04 19:28:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1LmMwMzVmMzUwLTBiNTMtNGE2Mi1iMGFhLTFmMDc0ZjczZWEzZHgxNzkxMTQyMTM3NzAwNzA1NzY28362026/10/04 19:28:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1LmMwMzVmMzUwLTBiNTMtNGE2Mi1iMGFhLTFmMDc0ZjczZWEzZHgxNzkxMTQyMTM3NzAwNzA1NzY2 parts=1837--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.70s)838=== CONT TestConnectWaitsForAPeerMigration839--- PASS: TestReadRedirectNar (0.45s)840=== CONT TestReadProxyNarinfoAlreadyDecompressed8412026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=08422026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period8432026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures8442026/10/04 19:28:57 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=08452026/10/04 19:28:57 INFO Vacuumed table table=pending_closures8462026/10/04 19:28:57 INFO Vacuumed table table=pending_objects8472026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads8482026/10/04 19:28:57 INFO Vacuumed table table=closures849--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.48s)850=== CONT TestResolveDBConnectionString851=== RUN TestResolveDBConnectionString/flag_wins852=== PAUSE TestResolveDBConnectionString/flag_wins853=== RUN TestResolveDBConnectionString/file_when_flag_empty854=== PAUSE TestResolveDBConnectionString/file_when_flag_empty855=== RUN TestResolveDBConnectionString/missing_file_is_an_error856=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error857=== RUN TestResolveDBConnectionString/PGHOST_allows_empty858=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty859=== RUN TestResolveDBConnectionString/nothing_configured860=== PAUSE TestResolveDBConnectionString/nothing_configured861=== CONT TestReadProxyNarinfo8622026/10/04 19:28:57 INFO Vacuumed table table=objects863--- PASS: TestGCSweepDeliversEachKeyOnce (0.76s)864=== CONT TestIsValidCachePath865=== RUN TestIsValidCachePath/narinfo866=== PAUSE TestIsValidCachePath/narinfo867=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars868=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars869=== RUN TestIsValidCachePath/nar_zst870=== PAUSE TestIsValidCachePath/nar_zst871=== RUN TestIsValidCachePath/nar_xz872=== PAUSE TestIsValidCachePath/nar_xz873=== RUN TestIsValidCachePath/nar_bz2874=== PAUSE TestIsValidCachePath/nar_bz2875=== RUN TestIsValidCachePath/nar_uncompressed876=== PAUSE TestIsValidCachePath/nar_uncompressed877=== RUN TestIsValidCachePath/ls878=== PAUSE TestIsValidCachePath/ls879=== RUN TestIsValidCachePath/log880=== PAUSE TestIsValidCachePath/log881=== RUN TestIsValidCachePath/realisation882=== PAUSE TestIsValidCachePath/realisation883=== RUN TestIsValidCachePath/nix-cache-info884=== PAUSE TestIsValidCachePath/nix-cache-info885=== RUN TestIsValidCachePath/index.html886=== PAUSE TestIsValidCachePath/index.html887=== RUN TestIsValidCachePath/traversal_parent888=== PAUSE TestIsValidCachePath/traversal_parent889=== RUN TestIsValidCachePath/traversal_in_middle890=== PAUSE TestIsValidCachePath/traversal_in_middle891=== RUN TestIsValidCachePath/invalid_char_e892=== PAUSE TestIsValidCachePath/invalid_char_e893=== RUN TestIsValidCachePath/invalid_char_u894=== PAUSE TestIsValidCachePath/invalid_char_u895=== RUN TestIsValidCachePath/random_path896=== PAUSE TestIsValidCachePath/random_path897=== RUN TestIsValidCachePath/empty898=== PAUSE TestIsValidCachePath/empty899=== RUN TestIsValidCachePath/leading_slash900=== PAUSE TestIsValidCachePath/leading_slash901=== RUN TestIsValidCachePath/wrong_extension902=== PAUSE TestIsValidCachePath/wrong_extension903=== RUN TestIsValidCachePath/short_hash904=== PAUSE TestIsValidCachePath/short_hash905=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9062026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures907--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.77s)908=== CONT TestProxyHeadersOnlyTrustedOnSocket9092026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=09102026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period9112026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures9122026/10/04 19:28:57 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=0913--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.48s)914=== CONT TestClientFallsBackToClosures9152026/10/04 19:28:57 INFO Vacuumed table table=pending_closures9162026/10/04 19:28:57 INFO Vacuumed table table=pending_objects9172026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads9182026/10/04 19:28:57 INFO Vacuumed table table=closures9192026/10/04 19:28:57 INFO Vacuumed table table=objects920--- PASS: TestReadProxyDisabled (0.46s)921=== CONT TestParseSingleRange922=== RUN TestParseSingleRange/none923=== PAUSE TestParseSingleRange/none924=== RUN TestParseSingleRange/unknown_unit925=== PAUSE TestParseSingleRange/unknown_unit926=== RUN TestParseSingleRange/multi-range_ignored927=== PAUSE TestParseSingleRange/multi-range_ignored928=== RUN TestParseSingleRange/malformed_no_dash929=== PAUSE TestParseSingleRange/malformed_no_dash930=== RUN TestParseSingleRange/malformed_both_empty931=== PAUSE TestParseSingleRange/malformed_both_empty932=== RUN TestParseSingleRange/malformed_end_before_start933=== PAUSE TestParseSingleRange/malformed_end_before_start934=== RUN TestParseSingleRange/closed935=== PAUSE TestParseSingleRange/closed936=== RUN TestParseSingleRange/open-ended937=== PAUSE TestParseSingleRange/open-ended938=== RUN TestParseSingleRange/end_clamped_to_size939=== PAUSE TestParseSingleRange/end_clamped_to_size940=== RUN TestParseSingleRange/suffix941=== PAUSE TestParseSingleRange/suffix942=== RUN TestParseSingleRange/suffix_exceeds_size943=== PAUSE TestParseSingleRange/suffix_exceeds_size944=== RUN TestParseSingleRange/single_byte945=== PAUSE TestParseSingleRange/single_byte946=== RUN TestParseSingleRange/start_past_EOF947=== PAUSE TestParseSingleRange/start_past_EOF948=== RUN TestParseSingleRange/start_far_past_EOF949=== PAUSE TestParseSingleRange/start_far_past_EOF950=== CONT TestClientPushesUseOnePush951--- PASS: TestGCSweepSkipsPendingObjects (0.49s)952=== CONT TestPresentNotReportedWhileGCDeletesClosure9532026/10/04 19:28:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9542026/10/04 19:28:57 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1LmIwYjQ1MTZiLWY5NDAtNGJhMC05M2JkLTRmNjEyMjFhNjcwMXgxNzkxMTQyMTM3NDk3NzA1MzEy parts=129552026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures9562026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures957--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.88s)958=== CONT TestPinProtectsFromGC9592026/10/04 19:28:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete960--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.48s)961=== CONT TestPresentReportsOnlyClosureRoots9622026/10/04 19:28:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1LmI5ZDgxMDQ4LWU1OTctNDhkMC1iYmI0LWNmYzVlMWYzZGQ5NHgxNzkxMTQyMTM3NTE1NzM4ODkx parts=129632026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures9642026/10/04 19:28:57 INFO Received uploads request method=POST path=/api/pending_closures9652026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=09662026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period9672026/10/04 19:28:57 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=09682026/10/04 19:28:57 INFO Vacuumed table table=pending_closures9692026/10/04 19:28:57 INFO Vacuumed table table=pending_objects9702026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads9712026/10/04 19:28:57 INFO Vacuumed table table=closures9722026/10/04 19:28:57 INFO Vacuumed table table=objects973--- PASS: TestGCMetrics (0.51s)974=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9752026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=0976--- PASS: TestReadProxyConditionalGet (0.52s)977=== CONT TestCreatePin_ReservedPins9782026/10/04 19:28:57 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=09792026/10/04 19:28:57 INFO Vacuumed table table=pending_closures9802026/10/04 19:28:57 INFO Vacuumed table table=pending_objects9812026/10/04 19:28:57 INFO Vacuumed table table=multipart_uploads9822026/10/04 19:28:57 INFO Vacuumed table table=closures9832026/10/04 19:28:57 INFO Vacuumed table table=objects9842026/10/04 19:28:57 INFO Aborted multipart uploads count=0 kept=09852026/10/04 19:28:57 WARN Force mode enabled - objects will be deleted immediately without grace period9862026/10/04 19:28:57 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=09872026/10/04 19:28:57 INFO Vacuumed table table=pending_closures9882026/10/04 19:28:58 INFO Vacuumed table table=pending_objects9892026/10/04 19:28:58 INFO Vacuumed table table=multipart_uploads9902026/10/04 19:28:58 INFO Vacuumed table table=closures9912026/10/04 19:28:58 INFO Vacuumed table table=objects992--- PASS: TestPushDedupSurvivesConcurrentGC (0.57s)993=== CONT TestClientSharedPathCommittedMidPush994--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.47s)995=== CONT TestIsValidUploadKey996=== RUN TestIsValidUploadKey/narinfo997=== PAUSE TestIsValidUploadKey/narinfo998=== RUN TestIsValidUploadKey/nar_zst999=== PAUSE TestIsValidUploadKey/nar_zst1000=== RUN TestIsValidUploadKey/nar_xz1001=== PAUSE TestIsValidUploadKey/nar_xz1002=== RUN TestIsValidUploadKey/nar_plain1003=== PAUSE TestIsValidUploadKey/nar_plain1004=== RUN TestIsValidUploadKey/listing1005=== PAUSE TestIsValidUploadKey/listing1006=== RUN TestIsValidUploadKey/build_log1007=== PAUSE TestIsValidUploadKey/build_log1008=== RUN TestIsValidUploadKey/build_log_home-manager_file1009=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1010=== RUN TestIsValidUploadKey/build_log_plus_in_name1011=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1012=== RUN TestIsValidUploadKey/build_log_question_mark1013=== PAUSE TestIsValidUploadKey/build_log_question_mark1014=== RUN TestIsValidUploadKey/build_log_equals1015=== PAUSE TestIsValidUploadKey/build_log_equals1016=== RUN TestIsValidUploadKey/realisation1017=== PAUSE TestIsValidUploadKey/realisation1018=== RUN TestIsValidUploadKey/realisation_plus_in_output1019=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1020=== RUN TestIsValidUploadKey/nix-cache-info1021=== PAUSE TestIsValidUploadKey/nix-cache-info1022=== RUN TestIsValidUploadKey/index.html1023=== PAUSE TestIsValidUploadKey/index.html1024=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1025=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1026=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1027=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1028=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1029=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1030=== RUN TestIsValidUploadKey/traversal1031=== PAUSE TestIsValidUploadKey/traversal1032=== RUN TestIsValidUploadKey/traversal_nar1033=== PAUSE TestIsValidUploadKey/traversal_nar1034=== RUN TestIsValidUploadKey/absolute1035=== PAUSE TestIsValidUploadKey/absolute1036=== RUN TestIsValidUploadKey/empty_key1037=== PAUSE TestIsValidUploadKey/empty_key1038=== RUN TestIsValidUploadKey/unknown_type1039=== PAUSE TestIsValidUploadKey/unknown_type1040=== CONT TestOrphanedObjectsGCStressTest1041--- PASS: TestReadProxyHead (0.46s)1042=== CONT TestClientWithDependencies1043--- PASS: TestReadProxyInvalidPath (0.42s)1044=== CONT TestClientMultipleUploads10452026/10/04 19:28:58 INFO lead: acquired remote=192.0.2.1:123410462026/10/04 19:28:58 INFO lead: acquired remote=192.0.2.1:12341047--- PASS: TestReadProxy404 (0.46s)1048=== CONT TestObjectStatsTrigger1049--- PASS: TestReadProxyNarStreaming (0.43s)1050=== CONT TestPendingClosureWriteTimeout1051=== RUN TestPendingClosureWriteTimeout/empty1052=== PAUSE TestPendingClosureWriteTimeout/empty1053=== RUN TestPendingClosureWriteTimeout/400_objects1054=== PAUSE TestPendingClosureWriteTimeout/400_objects1055=== RUN TestPendingClosureWriteTimeout/670k_objects1056=== PAUSE TestPendingClosureWriteTimeout/670k_objects1057=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1058=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1059=== CONT TestClientIntegration1060--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.41s)1061=== CONT TestPendingCleanupUsesOneCutoff1062--- PASS: TestPushWaitsForSweepHoldingRow (1.15s)1063=== CONT TestOrphanedObjectsGC1064--- PASS: TestGCBugBareHashReferences (0.71s)1065=== CONT TestClientErrorHandling1066=== RUN TestClientErrorHandling/InvalidStorePath1067=== PAUSE TestClientErrorHandling/InvalidStorePath1068=== RUN TestClientErrorHandling/InvalidAuthToken1069=== PAUSE TestClientErrorHandling/InvalidAuthToken1070=== RUN TestClientErrorHandling/ServerNotAvailable1071=== PAUSE TestClientErrorHandling/ServerNotAvailable1072=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10732026/10/04 19:28:58 INFO Starting HTTP server address=127.0.0.1:4465510742026/10/04 19:28:58 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2142242306/001/proxy.sock10752026/10/04 19:28:58 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10762026/10/04 19:28:58 INFO Shutdown signal received, draining in-flight requests timeout=10s1077--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.43s)1078=== CONT TestProxyWriteTimeout1079=== RUN TestProxyWriteTimeout/narinfo1080=== PAUSE TestProxyWriteTimeout/narinfo1081=== RUN TestProxyWriteTimeout/1_GiB_nar1082=== PAUSE TestProxyWriteTimeout/1_GiB_nar1083=== RUN TestProxyWriteTimeout/10_GiB_nar1084=== PAUSE TestProxyWriteTimeout/10_GiB_nar1085=== RUN TestProxyWriteTimeout/unknown_size1086=== PAUSE TestProxyWriteTimeout/unknown_size1087=== CONT TestClientCADerivations10882026/10/04 19:28:58 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10892026/10/04 19:28:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34877/oidc10902026/10/04 19:28:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10912026/10/04 19:28:58 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1LjEyNzc1ZDcxLTM0N2EtNDY2Zi04YWUzLTgxNjUyNzE5ZmRjMHgxNzkxMTQyMTM3OTQ3NDM0Mzg3 error="Get \"http://127.0.0.1:1/bucket15/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10922026/10/04 19:28:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1LmZmODU1NzE4LThiNzItNGMxMS05OWYwLTgxMTQ5NTRmNjY3MngxNzkxMTQyMTM3OTQwNzA2MDY4 parts=1210932026/10/04 19:28:58 INFO Received cleanup request method=DELETE path=/api/pending_closures10942026/10/04 19:28:58 INFO Aborted multipart uploads count=1 kept=01095--- PASS: TestRedundantMultipartUpload (1.31s)1096=== CONT TestMultipartCleanup1097--- PASS: TestPresentReportsOnlyClosureRoots (0.43s)1098=== CONT TestCompleteMultipartUnregistered10992026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures11002026/10/04 19:28:58 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161101--- PASS: TestReadProxyNarinfo (0.59s)1102=== CONT TestService_createPendingClosureHandler1103=== NAME TestPinProtectsFromGC1104 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4016299248/001/store/fwnn235wazgjdhq0k0nfsf7hnvd4ngkz-pinned-file.txt1105 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4016299248/001/store/bxv1slj7g7r188i84l8kpw07b83qyw7z-unpinned-file.txt11062026/10/04 19:28:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11072026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures11082026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/04 19:28:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11102026/10/04 19:28:58 INFO Uploading fdbg7qwfzxjwpd3vgmi8gvvkacaf4mqz-a (216B)11112026/10/04 19:28:58 INFO Uploading 3jr0xndzxrpw6mliw07ijwgpqy2xcz2a-shared-dep (136B)11122026/10/04 19:28:58 WARN Failed to register uploaded object key=zh60civjf5l07k6ixmnckab0vg2gj73y.ls error="server returned 404: 404 page not found\n"11132026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11142026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11152026/10/04 19:28:58 WARN Failed to register uploaded object key=3jr0xndzxrpw6mliw07ijwgpqy2xcz2a.ls error="server returned 404: 404 page not found\n"11162026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/0g4l39sxqrjqk290accjxh3d8rikj1041ii639gzd70zcp919sk8.nar.zst error="server returned 404: 404 page not found\n"11172026/10/04 19:28:58 WARN Failed to register uploaded object key=fdbg7qwfzxjwpd3vgmi8gvvkacaf4mqz.ls error="server returned 404: 404 page not found\n"11182026/10/04 19:28:58 INFO Signed narinfos id=1 count=211192026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11202026/10/04 19:28:58 INFO Signed narinfos id=2 count=211212026/10/04 19:28:58 INFO Uploading 4 narinfos11222026/10/04 19:28:58 WARN Failed to register uploaded object key=zh60civjf5l07k6ixmnckab0vg2gj73y.narinfo error="server returned 404: 404 page not found\n"11232026/10/04 19:28:58 WARN Failed to register uploaded object key=fdbg7qwfzxjwpd3vgmi8gvvkacaf4mqz.narinfo error="server returned 404: 404 page not found\n"11242026/10/04 19:28:58 WARN Failed to register uploaded object key=3jr0xndzxrpw6mliw07ijwgpqy2xcz2a.narinfo error="server returned 404: 404 page not found\n"11252026/10/04 19:28:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11262026/10/04 19:28:58 WARN Failed to register uploaded object key=3jr0xndzxrpw6mliw07ijwgpqy2xcz2a.narinfo error="server returned 404: 404 page not found\n"11272026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes11282026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes11292026/10/04 19:28:58 INFO Completed upload id=111302026/10/04 19:28:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11312026/10/04 19:28:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11322026/10/04 19:28:58 INFO Uploading fwnn235wazgjdhq0k0nfsf7hnvd4ngkz-pinned-file.txt (128B)11332026/10/04 19:28:58 INFO Completed upload id=211342026/10/04 19:28:58 INFO Upload complete. (85ms)11352026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11362026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11372026/10/04 19:28:58 WARN Failed to register uploaded object key=fwnn235wazgjdhq0k0nfsf7hnvd4ngkz.ls error="server returned 404: 404 page not found\n"11382026/10/04 19:28:58 INFO Signed narinfos id=1 count=111392026/10/04 19:28:58 INFO Uploading 1 narinfos11402026/10/04 19:28:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11412026/10/04 19:28:58 INFO Uploading c9py02bd6c9kbq8n1mnjrziy65b4nl1q-shared-dep (136B)11422026/10/04 19:28:58 INFO Uploading pbahcxh3l8sjjs7vlafx4h01lwx4w1jy-b (216B)1143=== NAME TestClientFallsBackToClosures1144 client_pushes_test.go:112: Retrieved narinfo from S3:1145 StorePath: /build/TestClientFallsBackToClosures1278532176/001/store/3jr0xndzxrpw6mliw07ijwgpqy2xcz2a-shared-dep1146 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1147 Compression: zstd1148 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821149 NarSize: 1361150 References: 1151 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1152 client_pushes_test.go:112: Retrieved narinfo from S3:1153 StorePath: /build/TestClientFallsBackToClosures1278532176/001/store/fdbg7qwfzxjwpd3vgmi8gvvkacaf4mqz-a1154 URL: nar/0g4l39sxqrjqk290accjxh3d8rikj1041ii639gzd70zcp919sk8.nar.zst1155 Compression: zstd1156 NarHash: sha256:0g4l39sxqrjqk290accjxh3d8rikj1041ii639gzd70zcp919sk81157 NarSize: 2161158 References: /build/TestClientFallsBackToClosures1278532176/001/store/3jr0xndzxrpw6mliw07ijwgpqy2xcz2a-shared-dep1159 CA: text:sha256:1jf2kpm6lyq4nqsx5wp4j402jni46ldjy61a7kzh7899bc6102kh11602026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/1/complete11612026/10/04 19:28:58 WARN Failed to register uploaded object key=fwnn235wazgjdhq0k0nfsf7hnvd4ngkz.narinfo error="server returned 404: 404 page not found\n"11622026/10/04 19:28:58 WARN Failed to register uploaded object key=c9py02bd6c9kbq8n1mnjrziy65b4nl1q.ls error="server returned 404: 404 page not found\n"11632026/10/04 19:28:58 WARN Failed to register uploaded object key=4zxqfm76a74xyfa1sjmvbk302wmwagm7.ls error="server returned 404: 404 page not found\n"11642026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/1l0vhlwydzpc36r42svd4y8xry3vx9prd6byflrh9r7vc9bcglpg.nar.zst error="server returned 404: 404 page not found\n"11652026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11662026/10/04 19:28:58 WARN Failed to register uploaded object key=pbahcxh3l8sjjs7vlafx4h01lwx4w1jy.ls error="server returned 404: 404 page not found\n"11672026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11682026/10/04 19:28:58 INFO Signed narinfos id=1 count=311692026/10/04 19:28:58 INFO Uploading 3 narinfos1170 client_pushes_test.go:112: Retrieved narinfo from S3:1171 StorePath: /build/TestClientFallsBackToClosures1278532176/001/store/zh60civjf5l07k6ixmnckab0vg2gj73y-b1172 URL: nar/0g4l39sxqrjqk290accjxh3d8rikj1041ii639gzd70zcp919sk8.nar.zst1173 Compression: zstd1174 NarHash: sha256:0g4l39sxqrjqk290accjxh3d8rikj1041ii639gzd70zcp919sk81175 NarSize: 2161176 References: /build/TestClientFallsBackToClosures1278532176/001/store/3jr0xndzxrpw6mliw07ijwgpqy2xcz2a-shared-dep1177 CA: text:sha256:1jf2kpm6lyq4nqsx5wp4j402jni46ldjy61a7kzh7899bc6102kh11782026/10/04 19:28:58 WARN Failed to register uploaded object key=c9py02bd6c9kbq8n1mnjrziy65b4nl1q.narinfo error="server returned 404: 404 page not found\n"11792026/10/04 19:28:58 WARN Failed to register uploaded object key=4zxqfm76a74xyfa1sjmvbk302wmwagm7.narinfo error="server returned 404: 404 page not found\n"11802026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/1/complete11812026/10/04 19:28:58 WARN Failed to register uploaded object key=pbahcxh3l8sjjs7vlafx4h01lwx4w1jy.narinfo error="server returned 404: 404 page not found\n"1182--- PASS: TestClientFallsBackToClosures (0.68s)1183=== CONT TestCacheStatsHandler1184--- PASS: TestObjectStatsTrigger (0.38s)1185=== CONT TestParseSize1186--- PASS: TestParseSize (0.00s)1187=== CONT TestService_verifyS3Integrity11882026/10/04 19:28:58 INFO Upload complete. (81ms)1189=== NAME TestClientMultipleUploads1190 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3948972116/001/store/ky8da3xh5c6nz89jx6ncf009dccdig7v-test-file-0.txt11912026/10/04 19:28:58 INFO Upload complete. (86ms)1192=== NAME TestClientPushesUseOnePush1193 client_pushes_test.go:97: Retrieved narinfo from S3:1194 StorePath: /build/TestClientPushesUseOnePush1167135526/001/store/c9py02bd6c9kbq8n1mnjrziy65b4nl1q-shared-dep1195 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1196 Compression: zstd1197 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821198 NarSize: 1361199 References: 1200 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1201=== NAME TestClientWithDependencies1202 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2198133156/001/store/zdcx9cc1sphw9ylx5qnm3hffzf1k7f9s-test-script1203=== NAME TestClientPushesUseOnePush1204 client_pushes_test.go:97: Retrieved narinfo from S3:1205 StorePath: /build/TestClientPushesUseOnePush1167135526/001/store/4zxqfm76a74xyfa1sjmvbk302wmwagm7-a1206 URL: nar/1l0vhlwydzpc36r42svd4y8xry3vx9prd6byflrh9r7vc9bcglpg.nar.zst1207 Compression: zstd1208 NarHash: sha256:1l0vhlwydzpc36r42svd4y8xry3vx9prd6byflrh9r7vc9bcglpg1209 NarSize: 2161210 References: /build/TestClientPushesUseOnePush1167135526/001/store/c9py02bd6c9kbq8n1mnjrziy65b4nl1q-shared-dep1211 CA: text:sha256:07as2300lb22glqjcl21apny7cjh4zhfwb8p0qa3nx0d9b3n42kp1212 client_pushes_test.go:97: Retrieved narinfo from S3:1213 StorePath: /build/TestClientPushesUseOnePush1167135526/001/store/pbahcxh3l8sjjs7vlafx4h01lwx4w1jy-b1214 URL: nar/1l0vhlwydzpc36r42svd4y8xry3vx9prd6byflrh9r7vc9bcglpg.nar.zst1215 Compression: zstd1216 NarHash: sha256:1l0vhlwydzpc36r42svd4y8xry3vx9prd6byflrh9r7vc9bcglpg1217 NarSize: 2161218 References: /build/TestClientPushesUseOnePush1167135526/001/store/c9py02bd6c9kbq8n1mnjrziy65b4nl1q-shared-dep1219 CA: text:sha256:07as2300lb22glqjcl21apny7cjh4zhfwb8p0qa3nx0d9b3n42kp1220--- PASS: TestClientPushesUseOnePush (0.70s)1221=== CONT TestCacheConfigHandler1222=== RUN TestCacheConfigHandler/full_config,_no_issuer1223=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1224=== RUN TestCacheConfigHandler/no_cache_url_configured1225=== PAUSE TestCacheConfigHandler/no_cache_url_configured1226=== RUN TestCacheConfigHandler/no_signing_keys1227=== PAUSE TestCacheConfigHandler/no_signing_keys1228=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1229=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1230=== CONT TestSkippedUploadsHandler12312026/10/04 19:28:58 INFO Client skipped oversized paths paths=3 nar_bytes=500000000012322026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes1233--- PASS: TestSkippedUploadsHandler (0.00s)1234=== CONT TestServerTLSConfig1235=== RUN TestServerTLSConfig/no_client_CA1236=== PAUSE TestServerTLSConfig/no_client_CA1237=== RUN TestServerTLSConfig/missing_CA_file1238=== PAUSE TestServerTLSConfig/missing_CA_file1239=== RUN TestServerTLSConfig/not_a_PEM_file1240=== PAUSE TestServerTLSConfig/not_a_PEM_file1241=== CONT TestService_ReadScope_PublicByDefault12422026/10/04 19:28:58 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12432026/10/04 19:28:58 INFO Uploading lmyy9rygz8vq896lw3lf633j6n4n3n44-shared-dep (136B)12442026/10/04 19:28:58 INFO Uploading mxfdywv9hwrgnhc2bi0gdm3d9k6cp6y4-top (224B)12452026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/110fx7m5ir0hkb324gvlpnqrinphlkjqpdzqdhh4ckp7hbmy3qfb.nar.zst error="server returned 404: 404 page not found\n"12462026/10/04 19:28:58 WARN Failed to register uploaded object key=mxfdywv9hwrgnhc2bi0gdm3d9k6cp6y4.ls error="server returned 404: 404 page not found\n"12472026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12482026/10/04 19:28:58 WARN Failed to register uploaded object key=lmyy9rygz8vq896lw3lf633j6n4n3n44.ls error="server returned 404: 404 page not found\n"12492026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12502026/10/04 19:28:58 INFO Signed narinfos id=1 count=212512026/10/04 19:28:58 INFO Uploading 2 narinfos1252=== NAME TestClientMultipleUploads1253 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3948972116/001/store/2g80jsd6ylw143i9wkaj15qfsmzf9q7w-test-file-1.txt12542026/10/04 19:28:58 WARN Failed to register uploaded object key=lmyy9rygz8vq896lw3lf633j6n4n3n44.narinfo error="server returned 404: 404 page not found\n"12552026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/1/complete12562026/10/04 19:28:58 WARN Failed to register uploaded object key=mxfdywv9hwrgnhc2bi0gdm3d9k6cp6y4.narinfo error="server returned 404: 404 page not found\n"1257=== NAME TestClientWithDependencies1258 client_integration_test.go:615: Found 1 dependencies (including self)12592026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures12602026/10/04 19:28:58 INFO Upload complete. (62ms)1261=== NAME TestClientSharedPathCommittedMidPush1262 client_integration_test.go:680: Retrieved narinfo from S3:1263 StorePath: /build/TestClientSharedPathCommittedMidPush4256999236/001/store/lmyy9rygz8vq896lw3lf633j6n4n3n44-shared-dep1264 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1265 Compression: zstd1266 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821267 NarSize: 1361268 References: 1269 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12702026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures1271 client_integration_test.go:680: Retrieved narinfo from S3:1272 StorePath: /build/TestClientSharedPathCommittedMidPush4256999236/001/store/mxfdywv9hwrgnhc2bi0gdm3d9k6cp6y4-top1273 URL: nar/110fx7m5ir0hkb324gvlpnqrinphlkjqpdzqdhh4ckp7hbmy3qfb.nar.zst1274 Compression: zstd1275 NarHash: sha256:110fx7m5ir0hkb324gvlpnqrinphlkjqpdzqdhh4ckp7hbmy3qfb1276 NarSize: 2241277 References: /build/TestClientSharedPathCommittedMidPush4256999236/001/store/lmyy9rygz8vq896lw3lf633j6n4n3n44-shared-dep1278 CA: text:sha256:0sssr91qb46a0zkcfx1157pd3951v0m6s0iy5fa8kdmmcjmryiwl1279--- PASS: TestClientSharedPathCommittedMidPush (0.56s)1280=== CONT TestService_Rustfstest12812026/10/04 19:28:58 INFO Received cleanup request method=DELETE path=/api/pending_closures1282=== NAME TestClientIntegration1283 client_integration_test.go:286: Created store path: /build/TestClientIntegration774506685/002/store/c5qhrwhb8sp5m39lc4yamfp0q09vh7jq-test-file.txt12842026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes12852026/10/04 19:28:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12862026/10/04 19:28:58 INFO Uploading bxv1slj7g7r188i84l8kpw07b83qyw7z-unpinned-file.txt (128B)1287=== NAME TestClientMultipleUploads1288 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3948972116/001/store/bzvbmccxl6j3x9z8rr1j0rl1h755mn1q-test-file-2.txt12892026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12902026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12912026/10/04 19:28:58 WARN Failed to register uploaded object key=bxv1slj7g7r188i84l8kpw07b83qyw7z.ls error="server returned 404: 404 page not found\n"12922026/10/04 19:28:58 INFO Signed narinfos id=2 count=112932026/10/04 19:28:58 INFO Uploading 1 narinfos12942026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/2/complete12952026/10/04 19:28:58 WARN Failed to register uploaded object key=bxv1slj7g7r188i84l8kpw07b83qyw7z.narinfo error="server returned 404: 404 page not found\n"12962026/10/04 19:28:58 INFO Upload complete. (43ms)12972026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures1298--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.40s)1299=== CONT TestGracefulShutdownDrainsInflight13002026/10/04 19:28:58 INFO Starting HTTP server address=127.0.0.1:3822313012026/10/04 19:28:58 INFO Shutdown signal received, draining in-flight requests timeout=10s1302--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.83s)1303=== CONT TestService_healthCheckHandler13042026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes13052026/10/04 19:28:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13062026/10/04 19:28:58 INFO Uploading zdcx9cc1sphw9ylx5qnm3hffzf1k7f9s-test-script (136B)13072026/10/04 19:28:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures13082026/10/04 19:28:58 INFO Garbage collection started13092026/10/04 19:28:58 WARN Failed to register uploaded object key=log/qn5iz43imzzg45ij7b15w8l5ywx65jg2-test-script.drv error="server returned 404: 404 page not found\n"13102026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13112026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13122026/10/04 19:28:58 WARN Failed to register uploaded object key=zdcx9cc1sphw9ylx5qnm3hffzf1k7f9s.ls error="server returned 404: 404 page not found\n"13132026/10/04 19:28:58 INFO Signed narinfos id=1 count=113142026/10/04 19:28:58 INFO Uploading 1 narinfos13152026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/1/complete13162026/10/04 19:28:58 WARN Failed to register uploaded object key=zdcx9cc1sphw9ylx5qnm3hffzf1k7f9s.narinfo error="server returned 404: 404 page not found\n"13172026/10/04 19:28:58 INFO Aborted multipart uploads count=0 kept=013182026/10/04 19:28:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13192026/10/04 19:28:58 WARN Refused reserved pin name=worker-x86_64-linux13202026/10/04 19:28:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13212026/10/04 19:28:58 INFO Received create pin request method=POST path=/api/pins/my-app13222026/10/04 19:28:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1323--- PASS: TestCreatePin_ReservedPins (0.67s)1324=== CONT TestService_RequireScope_OIDC13252026/10/04 19:28:58 INFO Upload complete. (56ms)13262026/10/04 19:28:58 WARN Force mode enabled - objects will be deleted immediately without grace period1327=== NAME TestClientWithDependencies1328 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2198133156/001/store) requires matching store prefix13292026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes13302026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes1331--- PASS: TestClientWithDependencies (0.60s)1332=== CONT TestGCTaskStore_Fail1333--- PASS: TestGCTaskStore_Fail (0.00s)1334=== CONT TestCreatePendingClosureRejectsOversizedNAR13352026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures1336--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1337=== CONT TestCacheConfigHandlerMaxNarSize1338--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1339=== CONT TestGCTaskStore_PhaseUpdates1340--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1341=== CONT TestGenerateLandingPage13422026/10/04 19:28:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13432026/10/04 19:28:58 INFO Uploading c5qhrwhb8sp5m39lc4yamfp0q09vh7jq-test-file.txt (152B)1344--- PASS: TestGenerateLandingPage (0.00s)1345=== CONT TestService_AuthMiddleware_OIDC13462026/10/04 19:28:58 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13472026/10/04 19:28:58 INFO Uploading 2g80jsd6ylw143i9wkaj15qfsmzf9q7w-test-file-1.txt (160B)13482026/10/04 19:28:58 INFO Uploading bzvbmccxl6j3x9z8rr1j0rl1h755mn1q-test-file-2.txt (160B)13492026/10/04 19:28:58 INFO Uploading ky8da3xh5c6nz89jx6ncf009dccdig7v-test-file-0.txt (160B)13502026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures1351--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1352=== CONT TestGCTaskStore_CompletedAllowsNewTask1353--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1354=== CONT TestService_readinessHandler13552026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13562026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13572026/10/04 19:28:58 WARN Failed to register uploaded object key=c5qhrwhb8sp5m39lc4yamfp0q09vh7jq.ls error="server returned 404: 404 page not found\n"13582026/10/04 19:28:58 INFO Signed narinfos id=1 count=113592026/10/04 19:28:58 INFO Uploading 1 narinfos13602026/10/04 19:28:58 WARN Failed to register uploaded object key=2g80jsd6ylw143i9wkaj15qfsmzf9q7w.ls error="server returned 404: 404 page not found\n"13612026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13622026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13632026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13642026/10/04 19:28:58 WARN Failed to register uploaded object key=bzvbmccxl6j3x9z8rr1j0rl1h755mn1q.ls error="server returned 404: 404 page not found\n"13652026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13662026/10/04 19:28:58 WARN Failed to register uploaded object key=ky8da3xh5c6nz89jx6ncf009dccdig7v.ls error="server returned 404: 404 page not found\n"13672026/10/04 19:28:58 INFO Signed narinfos id=1 count=313682026/10/04 19:28:58 INFO Uploading 3 narinfos13692026/10/04 19:28:58 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=013702026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/1/complete13712026/10/04 19:28:58 WARN Failed to register uploaded object key=c5qhrwhb8sp5m39lc4yamfp0q09vh7jq.narinfo error="server returned 404: 404 page not found\n"13722026/10/04 19:28:58 WARN Failed to register uploaded object key=2g80jsd6ylw143i9wkaj15qfsmzf9q7w.narinfo error="server returned 404: 404 page not found\n"13732026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/1/complete13742026/10/04 19:28:58 WARN Failed to register uploaded object key=bzvbmccxl6j3x9z8rr1j0rl1h755mn1q.narinfo error="server returned 404: 404 page not found\n"13752026/10/04 19:28:58 INFO Vacuumed table table=pending_closures13762026/10/04 19:28:58 WARN Failed to register uploaded object key=ky8da3xh5c6nz89jx6ncf009dccdig7v.narinfo error="server returned 404: 404 page not found\n"13772026/10/04 19:28:58 INFO Upload complete. (84ms)13782026/10/04 19:28:58 INFO Vacuumed table table=pending_objects13792026/10/04 19:28:58 INFO Vacuumed table table=multipart_uploads1380=== NAME TestClientCADerivations1381 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4049935698/001/store/4p2grng4mj9rvfqb1y4dlbavfw8lgm18-ca-test13822026/10/04 19:28:58 INFO Upload complete. (84ms)1383=== NAME TestClientMultipleUploads1384 client_integration_test.go:369: Uploaded 3 paths in 112.206632ms13852026/10/04 19:28:58 INFO Vacuumed table table=closures13862026/10/04 19:28:58 INFO Vacuumed table table=objects13872026/10/04 19:28:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13882026/10/04 19:28:58 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1389--- PASS: TestCompleteMultipartUnregistered (0.35s)1390=== CONT TestGCTaskStore_GetReturnsLatest1391--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1392=== CONT TestGCTaskStore_ConflictDifferentParams1393--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1394=== CONT TestGCTaskStore_DeduplicateSameParams1395--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1396=== CONT TestService_ReadAuthMiddleware1397--- PASS: TestClientMultipleUploads (0.64s)1398=== CONT TestGCTaskStore_GetEmpty1399--- PASS: TestGCTaskStore_GetEmpty (0.00s)1400=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14012026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures14022026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures14032026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures14042026/10/04 19:28:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35929/oidc1405=== NAME TestClientCADerivations1406 client_ca_test.go:139: Found 1 dependencies (including self)14072026/10/04 19:28:58 INFO All 1 paths already cached1408=== NAME TestClientIntegration1409 client_integration_test.go:312: Retrieved narinfo from S3:1410 StorePath: /build/TestClientIntegration774506685/002/store/c5qhrwhb8sp5m39lc4yamfp0q09vh7jq-test-file.txt1411 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1412 Compression: zstd1413 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11414 NarSize: 1521415 References: 1416 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11417 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1418 client_integration_test.go:313: Decompressed .ls content (64 bytes):1419 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1420 client_integration_test.go:316: Testing garbage collection...14212026/10/04 19:28:58 INFO Received uploads request method=POST path=/api/pending_closures14222026/10/04 19:28:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures14232026/10/04 19:28:58 INFO Garbage collection started1424--- PASS: TestCacheStatsHandler (0.26s)1425=== CONT TestMetricsInventory14262026/10/04 19:28:58 INFO Aborted multipart uploads count=0 kept=014272026/10/04 19:28:58 WARN Force mode enabled - objects will be deleted immediately without grace period14282026/10/04 19:28:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46351/oidc1429--- PASS: TestService_ReadScope_PublicByDefault (0.24s)1430=== CONT TestService_AuthMiddleware_MTLSProxyHeader1431--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.95s)1432=== CONT TestService_NativeMTLS14332026/10/04 19:28:58 INFO Received cleanup request method=DELETE path=/api/pending_closures14342026/10/04 19:28:58 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket66/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14352026/10/04 19:28:58 INFO Aborted multipart uploads count=0 kept=114362026/10/04 19:28:58 INFO Received cleanup request method=DELETE path=/api/pending_closures14372026/10/04 19:28:58 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=014382026/10/04 19:28:58 INFO Aborted multipart uploads count=1 kept=014392026/10/04 19:28:58 INFO Vacuumed table table=pending_closures1440--- PASS: TestMultipartCleanup (0.46s)1441=== CONT TestNARDeduplicationMetadataUploadBug14422026/10/04 19:28:58 INFO Vacuumed table table=pending_objects14432026/10/04 19:28:58 INFO Vacuumed table table=multipart_uploads1444--- PASS: TestService_Rustfstest (0.24s)1445=== CONT TestService_cleanupPendingClosuresHandler14462026/10/04 19:28:58 INFO Vacuumed table table=closures14472026/10/04 19:28:58 INFO Vacuumed table table=objects14482026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes1449--- PASS: TestService_healthCheckHandler (0.21s)1450=== CONT TestUploadHandlersRejectOversizedBody14512026/10/04 19:28:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14522026/10/04 19:28:58 INFO Uploading 4p2grng4mj9rvfqb1y4dlbavfw8lgm18-ca-test (144B)14532026/10/04 19:28:58 WARN Failed to register uploaded object key=4p2grng4mj9rvfqb1y4dlbavfw8lgm18.ls error="server returned 404: 404 page not found\n"14542026/10/04 19:28:58 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14552026/10/04 19:28:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14562026/10/04 19:28:58 WARN Failed to register uploaded object key=log/s5q93f037vamdm6jsfrf5qxs6l44wwp7-ca-test.drv error="server returned 404: 404 page not found\n"14572026/10/04 19:28:58 INFO Signed narinfos id=1 count=114582026/10/04 19:28:58 INFO Uploading 1 narinfos14592026/10/04 19:28:58 INFO Received complete push request method=POST path=/api/pushes/1/complete14602026/10/04 19:28:58 WARN Failed to register uploaded object key=4p2grng4mj9rvfqb1y4dlbavfw8lgm18.narinfo error="server returned 404: 404 page not found\n"14612026/10/04 19:28:58 INFO Upload complete. (93ms)14622026/10/04 19:28:58 WARN readiness check failed error="closed pool"1463--- PASS: TestService_readinessHandler (0.18s)1464=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1465=== NAME TestClientCADerivations1466 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4049935698/001/store/4p2grng4mj9rvfqb1y4dlbavfw8lgm18-ca-test1467 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1468 Compression: zstd1469 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1470 NarSize: 1441471 References: 1472 Deriver: /build/TestClientCADerivations4049935698/001/store/s5q93f037vamdm6jsfrf5qxs6l44wwp7-ca-test.drv1473 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1474 client_ca_test.go:185: Checking for realisation files in S3...1475 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1476 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14772026/10/04 19:28:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14782026/10/04 19:28:58 WARN mTLS auth: bound subjects configured but subject DN unavailable14792026/10/04 19:28:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1480--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.17s)1481=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1482=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1483=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1484=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1485=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1486=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1487=== NAME TestClientCADerivations1488 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1489 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1490 error: binary cache 's3://bucket64?endpoint=http://localhost:40219®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4049935698/001/store'1491 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11492=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1493=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1494--- PASS: TestService_ReadAuthMiddleware (0.26s)14952026/10/04 19:28:58 INFO Received uploads request method=POST path=/1496=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1497=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14982026/10/04 19:28:58 INFO Received complete multipart upload request method=POST path=/1499=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15002026/10/04 19:28:58 INFO Received request for more parts method=POST path=/15012026/10/04 19:28:58 INFO Received uploads request method=POST path=/1502=== CONT TestPush_RejectsBadRequests/no_roots1503--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1504 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1505 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1506 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1507 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)15082026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes1509=== CONT TestPush_RejectsBadRequests/bad_root1510=== CONT TestPush_RejectsBadRequests/root_not_in_objects15112026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes15122026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes1513=== CONT TestPush_RejectsBadRequests/no_objects1514=== CONT TestResolveDBConnectionString/flag_wins15152026/10/04 19:28:58 INFO Received push request method=POST path=/api/pushes1516=== CONT TestResolveDBConnectionString/nothing_configured1517=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1518=== CONT TestResolveDBConnectionString/file_when_flag_empty1519--- PASS: TestPush_RejectsBadRequests (0.32s)1520 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1521 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1522 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1523 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1524=== CONT TestResolveDBConnectionString/missing_file_is_an_error1525=== CONT TestIsValidCachePath/narinfo1526=== CONT TestIsValidCachePath/leading_slash1527=== CONT TestIsValidCachePath/empty1528=== CONT TestIsValidCachePath/invalid_char_u1529=== CONT TestIsValidCachePath/wrong_extension1530=== CONT TestIsValidCachePath/invalid_char_e1531=== CONT TestIsValidCachePath/traversal_in_middle1532=== CONT TestIsValidCachePath/traversal_parent1533=== CONT TestIsValidCachePath/index.html1534=== CONT TestIsValidCachePath/nix-cache-info1535=== CONT TestIsValidCachePath/realisation1536=== CONT TestIsValidCachePath/log1537=== CONT TestIsValidCachePath/ls1538=== CONT TestIsValidCachePath/nar_uncompressed1539=== CONT TestIsValidCachePath/nar_bz21540=== CONT TestIsValidCachePath/nar_xz1541=== CONT TestIsValidCachePath/nar_zst1542=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1543=== CONT TestIsValidCachePath/short_hash1544=== CONT TestParseSingleRange/none1545=== CONT TestParseSingleRange/start_past_EOF1546=== CONT TestParseSingleRange/single_byte1547=== CONT TestParseSingleRange/suffix_exceeds_size1548=== CONT TestParseSingleRange/suffix1549=== CONT TestParseSingleRange/end_clamped_to_size1550=== CONT TestParseSingleRange/open-ended1551=== CONT TestParseSingleRange/closed1552--- PASS: TestResolveDBConnectionString (0.00s)1553 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1554 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1555 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1556 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1557 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1558=== CONT TestParseSingleRange/malformed_end_before_start1559=== CONT TestParseSingleRange/start_far_past_EOF1560=== CONT TestParseSingleRange/malformed_both_empty1561=== CONT TestParseSingleRange/malformed_no_dash1562=== CONT TestParseSingleRange/multi-range_ignored1563=== CONT TestParseSingleRange/unknown_unit1564--- PASS: TestParseSingleRange (0.00s)1565 --- PASS: TestParseSingleRange/none (0.00s)1566 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1567 --- PASS: TestParseSingleRange/single_byte (0.00s)1568 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1569 --- PASS: TestParseSingleRange/suffix (0.00s)1570 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1571 --- PASS: TestParseSingleRange/open-ended (0.00s)1572 --- PASS: TestParseSingleRange/closed (0.00s)1573 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1574 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1575 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1576 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1577 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1578 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1579=== CONT TestIsValidCachePath/random_path1580--- PASS: TestIsValidCachePath (0.00s)1581 --- PASS: TestIsValidCachePath/narinfo (0.00s)1582 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1583 --- PASS: TestIsValidCachePath/empty (0.00s)1584 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1585 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1586 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1587 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1588 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1589 --- PASS: TestIsValidCachePath/index.html (0.00s)1590 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1591 --- PASS: TestIsValidCachePath/realisation (0.00s)1592 --- PASS: TestIsValidCachePath/log (0.00s)1593 --- PASS: TestIsValidCachePath/ls (0.00s)1594 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1595 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1596 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1597 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1598 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1599 --- PASS: TestIsValidCachePath/short_hash (0.00s)1600 --- PASS: TestIsValidCachePath/random_path (0.00s)1601=== CONT TestIsValidUploadKey/narinfo1602=== CONT TestIsValidUploadKey/empty_key1603=== CONT TestIsValidUploadKey/traversal_nar1604=== CONT TestIsValidUploadKey/traversal1605=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1606=== CONT TestIsValidUploadKey/unknown_type1607=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1608=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1609=== CONT TestIsValidUploadKey/absolute1610=== CONT TestIsValidUploadKey/index.html1611=== CONT TestIsValidUploadKey/realisation_plus_in_output1612=== CONT TestIsValidUploadKey/realisation1613=== CONT TestIsValidUploadKey/listing1614=== CONT TestIsValidUploadKey/nar_plain1615=== CONT TestIsValidUploadKey/nar_xz1616=== CONT TestIsValidUploadKey/nix-cache-info1617=== CONT TestIsValidUploadKey/build_log_question_mark1618=== CONT TestIsValidUploadKey/build_log_equals1619=== CONT TestIsValidUploadKey/nar_zst1620=== CONT TestIsValidUploadKey/build_log1621=== CONT TestIsValidUploadKey/build_log_home-manager_file1622=== CONT TestIsValidUploadKey/build_log_plus_in_name1623--- PASS: TestIsValidUploadKey (0.00s)1624 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1625 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1626 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1627 --- PASS: TestIsValidUploadKey/traversal (0.00s)1628 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1629 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1630 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1631 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1632 --- PASS: TestIsValidUploadKey/absolute (0.00s)1633 --- PASS: TestIsValidUploadKey/index.html (0.00s)1634 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1635 --- PASS: TestIsValidUploadKey/realisation (0.00s)1636 --- PASS: TestIsValidUploadKey/listing (0.00s)1637 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1638 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1639 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1640 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1641 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1642 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1643 --- PASS: TestIsValidUploadKey/build_log (0.00s)1644 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1645 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1646=== CONT TestPendingClosureWriteTimeout/empty1647=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1648=== CONT TestPendingClosureWriteTimeout/670k_objects1649=== CONT TestPendingClosureWriteTimeout/400_objects1650--- PASS: TestClientCADerivations (0.74s)1651=== CONT TestClientErrorHandling/ServerNotAvailable1652=== CONT TestClientErrorHandling/InvalidStorePath1653=== NAME TestOrphanedObjectsGC1654 orphaned_objects_gc_test.go:290: GC Test Summary:1655 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1656 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1657 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1658 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1659 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1660--- PASS: TestOrphanedObjectsGC (0.80s)1661=== CONT TestClientErrorHandling/InvalidAuthToken1662=== RUN TestService_RequireScope_OIDC/builder_may_write1663=== PAUSE TestService_RequireScope_OIDC/builder_may_write1664=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1665=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1666=== RUN TestService_RequireScope_OIDC/ops_may_admin1667=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1668=== RUN TestService_RequireScope_OIDC/ops_may_not_write1669=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1670=== RUN TestService_RequireScope_OIDC/reader_may_not_write1671=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1672=== RUN TestService_RequireScope_OIDC/static_token_may_admin1673=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1674=== RUN TestService_RequireScope_OIDC/static_token_may_write1675=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1676=== RUN TestService_RequireScope_OIDC/reader_may_read1677=== PAUSE TestService_RequireScope_OIDC/reader_may_read1678=== RUN TestService_RequireScope_OIDC/writer_implies_read1679=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1680=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1681=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1682=== CONT TestProxyWriteTimeout/narinfo1683=== CONT TestProxyWriteTimeout/unknown_size1684=== CONT TestProxyWriteTimeout/10_GiB_nar1685=== CONT TestProxyWriteTimeout/1_GiB_nar1686--- PASS: TestProxyWriteTimeout (0.00s)1687 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1688 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1689 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1690 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1691=== CONT TestCacheConfigHandler/full_config,_no_issuer1692=== CONT TestCacheConfigHandler/no_cache_url_configured1693=== CONT TestCacheConfigHandler/no_signing_keys1694=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1695--- PASS: TestCacheConfigHandler (0.00s)1696 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1697 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1698 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1699 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1700=== CONT TestServerTLSConfig/no_client_CA1701=== CONT TestServerTLSConfig/missing_CA_file1702=== CONT TestServerTLSConfig/not_a_PEM_file1703--- PASS: TestServerTLSConfig (0.00s)1704 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1705 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1706 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1707=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17082026/10/04 19:28:59 INFO Received uploads request method=POST path=/1709--- PASS: TestMetricsInventory (0.26s)1710=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17112026/10/04 19:28:59 INFO Received request for more parts method=POST path=/1712--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.25s)1713=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17142026/10/04 19:28:59 INFO Received complete multipart upload request method=POST path=/17152026/10/04 19:28:59 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/present1716=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1717=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1718=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1719=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1720=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1721=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1722=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1723=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1724=== CONT TestService_RequireScope_OIDC/builder_may_write1725=== CONT TestService_RequireScope_OIDC/static_token_may_admin1726=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1727=== CONT TestService_RequireScope_OIDC/static_token_may_write1728=== CONT TestService_RequireScope_OIDC/ops_may_not_write1729=== CONT TestService_RequireScope_OIDC/reader_may_not_write1730=== CONT TestService_RequireScope_OIDC/reader_may_read1731=== CONT TestService_RequireScope_OIDC/ops_may_admin1732=== CONT TestService_RequireScope_OIDC/writer_implies_read1733=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1734=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1735--- PASS: TestService_RequireScope_OIDC (0.37s)1736 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1737 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1738 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1739 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1740 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1741 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1742 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1743 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1744 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1745 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1746=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1747=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17482026/10/04 19:28:59 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]1749=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17502026/10/04 19:28:59 WARN Authentication failed token_preview=eyJhbGciOi...5YM6V95GWg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1751--- PASS: TestService_AuthMiddleware_OIDC (0.40s)1752 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1753 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1754 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1755 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17562026/10/04 19:28:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17572026/10/04 19:28:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1758--- PASS: TestService_NativeMTLS (0.29s)17592026/10/04 19:28:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17602026/10/04 19:28:59 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1LjQ3MDhiY2I0LTA0NDgtNDE4Yy04MzExLTRhMTkyMGFkYTk0NngxNzkxMTQyMTM4NzI0NzcxODM5 parts=1017612026/10/04 19:28:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17622026/10/04 19:28:59 INFO Completed upload id=117632026/10/04 19:28:59 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017642026/10/04 19:28:59 INFO Received uploads request method=POST path=/api/pending_closures17652026/10/04 19:28:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures17662026/10/04 19:28:59 INFO Received cleanup request method=DELETE path=/api/pending_closures17672026/10/04 19:28:59 INFO Aborted multipart uploads count=0 kept=017682026/10/04 19:28:59 INFO Aborted multipart uploads count=0 kept=017692026/10/04 19:28:59 INFO Received uploads request method=POST path=/api/pending_closures17702026/10/04 19:28:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17712026/10/04 19:28:59 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=017722026/10/04 19:28:59 INFO Received cleanup request method=DELETE path=/api/pending_closures17732026/10/04 19:28:59 INFO Vacuumed table table=pending_closures17742026/10/04 19:28:59 INFO Vacuumed table table=pending_objects17752026/10/04 19:28:59 INFO Aborted multipart uploads count=1 kept=017762026/10/04 19:28:59 INFO Vacuumed table table=multipart_uploads17772026/10/04 19:28:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17782026-10-04 19:28:59.115 UTC [1467] ERROR: Closure does not exist: id=117792026-10-04 19:28:59.115 UTC [1467] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE17802026-10-04 19:28:59.115 UTC [1467] STATEMENT: -- name: CommitPendingClosure :exec1781 SELECT commit_pending_closure($1::bigint)1782 1783--- PASS: TestService_cleanupPendingClosuresHandler (0.31s)17842026/10/04 19:28:59 INFO Vacuumed table table=closures17852026/10/04 19:28:59 INFO Vacuumed table table=objects17862026/10/04 19:28:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzgzMmNjMjAtMzIzMy00MzBkLWE3YjYtZTkzMmVmMzk3NTY1Ljc5MzhlMjgzLTVmYzgtNDdkZC05OWU4LThmNWViM2YyNzUwYngxNzkxMTQyMTM4NzQ5NjQ4ODU5 parts=1017872026/10/04 19:28:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17882026/10/04 19:28:59 INFO Completed upload id=117892026/10/04 19:28:59 INFO Received uploads request method=POST path=/api/pending_closures17902026/10/04 19:28:59 INFO Received uploads request method=POST path=/api/pending_closures17912026/10/04 19:28:59 INFO Received uploads request method=POST path=/api/pending_closures1792=== NAME TestNARDeduplicationMetadataUploadBug1793 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1162366076/001/store/05f4gln856fqpwmavbbl21vsmgbps5qi-file1.txt17942026/10/04 19:28:59 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17952026/10/04 19:28:59 WARN Found objects in DB but missing from S3, will re-upload count=11796--- PASS: TestService_verifyS3Integrity (0.62s)17972026/10/04 19:28:59 INFO Aborted multipart uploads count=0 kept=017982026/10/04 19:28:59 WARN Force mode enabled - objects will be deleted immediately without grace period17992026/10/04 19:28:59 INFO Received uploads request method=POST path=/api/pending_closures18002026/10/04 19:28:59 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=018012026/10/04 19:28:59 INFO Vacuumed table table=pending_closures18022026/10/04 19:28:59 INFO Vacuumed table table=pending_objects18032026/10/04 19:28:59 INFO Vacuumed table table=multipart_uploads18042026/10/04 19:28:59 INFO Vacuumed table table=closures18052026/10/04 19:28:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.956035ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18062026/10/04 19:28:59 INFO Vacuumed table table=objects18072026/10/04 19:28:59 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001808--- PASS: TestService_createPendingClosureHandler (0.77s)18092026/10/04 19:28:59 INFO Aborted multipart uploads count=0 kept=018102026/10/04 19:28:59 WARN Force mode enabled - objects will be deleted immediately without grace period18112026/10/04 19:28:59 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=018122026/10/04 19:28:59 INFO Vacuumed table table=pending_closures18132026/10/04 19:28:59 INFO Vacuumed table table=pending_objects18142026/10/04 19:28:59 INFO Vacuumed table table=multipart_uploads18152026/10/04 19:28:59 INFO Vacuumed table table=closures18162026/10/04 19:28:59 INFO Vacuumed table table=objects18172026/10/04 19:28:59 INFO Received uploads request method=POST path=/api/pending_closures1818--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1819 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.31s)1820 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.29s)18212026/10/04 19:28:59 INFO lead: released remote=192.0.2.1:12341822--- PASS: TestLeadEndsOnShutdown (1.54s)18232026/10/04 19:28:59 INFO Received push request method=POST path=/api/pushes18242026/10/04 19:28:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18252026/10/04 19:28:59 INFO Uploading 05f4gln856fqpwmavbbl21vsmgbps5qi-file1.txt (160B)18262026/10/04 19:28:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18272026/10/04 19:28:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18282026/10/04 19:28:59 INFO Signed narinfos id=1 count=118292026/10/04 19:28:59 WARN Failed to register uploaded object key=05f4gln856fqpwmavbbl21vsmgbps5qi.ls error="server returned 404: 404 page not found\n"18302026/10/04 19:28:59 INFO Uploading 1 narinfos18312026/10/04 19:28:59 INFO Received complete push request method=POST path=/api/pushes/1/complete18322026/10/04 19:28:59 WARN Failed to register uploaded object key=05f4gln856fqpwmavbbl21vsmgbps5qi.narinfo error="server returned 404: 404 page not found\n"18332026/10/04 19:28:59 INFO Upload complete. (47ms)1834=== NAME TestNARDeduplicationMetadataUploadBug1835 metadata_upload_test.go:54: Retrieved narinfo from S3:1836 StorePath: /build/TestNARDeduplicationMetadataUploadBug1162366076/001/store/05f4gln856fqpwmavbbl21vsmgbps5qi-file1.txt1837 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1838 Compression: zstd1839 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1840 NarSize: 1601841 References: 1842 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1843 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1844 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1845 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1846 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1162366076/001/store/748as6chqi4bk81mfxh33vkh9ydw0dpn-file2.txt18472026/10/04 19:28:59 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18482026/10/04 19:28:59 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18492026/10/04 19:28:59 INFO Received push request method=POST path=/api/pushes18502026/10/04 19:28:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18512026/10/04 19:28:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18522026/10/04 19:28:59 WARN Failed to register uploaded object key=748as6chqi4bk81mfxh33vkh9ydw0dpn.ls error="server returned 404: 404 page not found\n"18532026/10/04 19:28:59 INFO Signed narinfos id=2 count=118542026/10/04 19:28:59 INFO Uploading 1 narinfos18552026/10/04 19:28:59 INFO Received complete push request method=POST path=/api/pushes/2/complete18562026/10/04 19:28:59 WARN Failed to register uploaded object key=748as6chqi4bk81mfxh33vkh9ydw0dpn.narinfo error="server returned 404: 404 page not found\n"18572026/10/04 19:28:59 INFO Upload complete. (40ms)1858 metadata_upload_test.go:76: Retrieved narinfo from S3:1859 StorePath: /build/TestNARDeduplicationMetadataUploadBug1162366076/001/store/748as6chqi4bk81mfxh33vkh9ydw0dpn-file2.txt1860 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1861 Compression: zstd1862 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1863 NarSize: 1601864 References: 1865 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1866 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1867 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1868 {"version":1,"root":{"type":"regular","size":44}}1869--- PASS: TestNARDeduplicationMetadataUploadBug (0.52s)18702026/10/04 19:28:59 INFO lead: released remote=192.0.2.1:123418712026/10/04 19:28:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.444703ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18722026/10/04 19:28:59 INFO lead: acquired remote=192.0.2.1:12341873=== NAME TestOrphanedObjectsGCStressTest1874 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1875 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18762026/10/04 19:28:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=742.67055ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1877 orphaned_objects_gc_test.go:509: Stress test completed successfully:1878 orphaned_objects_gc_test.go:510: - Active objects preserved: 201879 orphaned_objects_gc_test.go:511: - Objects deleted: 2101880 orphaned_objects_gc_test.go:512: - Total GC'd: 2101881--- PASS: TestOrphanedObjectsGCStressTest (1.81s)1882--- PASS: TestPendingClosureWriteTimeout (0.00s)1883 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1884 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1885 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1886 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.00s)1887--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1888 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1889 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1890 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.02s)18912026/10/04 19:29:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.65106446s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18922026/10/04 19:29:00 INFO lead: released remote=192.0.2.1:12341893--- PASS: TestLeadElectsOneAndHandsOver (2.79s)18942026/10/04 19:29:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018952026/10/04 19:29:00 INFO Received create pin request method=POST path=/api/pins/myapp18962026/10/04 19:29:00 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4016299248/001/store/fwnn235wazgjdhq0k0nfsf7hnvd4ngkz-pinned-file.txt narinfo_key=fwnn235wazgjdhq0k0nfsf7hnvd4ngkz.narinfo18972026/10/04 19:29:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures18982026/10/04 19:29:00 INFO Garbage collection started18992026/10/04 19:29:00 INFO Aborted multipart uploads count=0 kept=019002026/10/04 19:29:00 WARN Force mode enabled - objects will be deleted immediately without grace period19012026/10/04 19:29:00 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=019022026/10/04 19:29:00 INFO Vacuumed table table=pending_closures19032026/10/04 19:29:00 INFO Vacuumed table table=pending_objects19042026/10/04 19:29:00 INFO Vacuumed table table=multipart_uploads19052026/10/04 19:29:00 INFO Vacuumed table table=closures19062026/10/04 19:29:00 INFO Vacuumed table table=objects19072026/10/04 19:29:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01908=== NAME TestClientIntegration1909 client_integration_test.go:323: Objects in database after GC:1910 client_integration_test.go:323: Successfully deleted all objects with GC --force1911--- PASS: TestClientIntegration (2.62s)19122026/10/04 19:29:02 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-config1913--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.70s)19142026/10/04 19:29:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.393192ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19152026/10/04 19:29:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=371.349888ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1916=== NAME TestPinProtectsFromGC1917 client_integration_test.go:840: Pin successfully protected closure from garbage collection1918--- PASS: TestPinProtectsFromGC (4.74s)19192026/10/04 19:29:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=791.449399ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1920--- PASS: TestConnectWaitsForAPeerMigration (5.12s)19212026/10/04 19:29:03 WARN Rate limiter enabled after throttle name=s3-test rate=519222026/10/04 19:29:03 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1923=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1924 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101925 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001926--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.10s)19272026/10/04 19:29:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.750052236s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19282026/10/04 19:29:04 INFO Aborted multipart uploads count=1 kept=019292026/10/04 19:29:04 INFO Received cleanup request method=DELETE path=/api/pending_closures19302026/10/04 19:29:04 INFO Aborted multipart uploads count=1 kept=01931--- PASS: TestPendingCleanupUsesOneCutoff (6.41s)19322026/10/04 19:29:05 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"19332026/10/04 19:29:05 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-config19342026/10/04 19:29:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.860172ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19352026/10/04 19:29:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.925159ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19362026/10/04 19:29:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.821901ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19372026/10/04 19:29:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.568885534s 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:29:08 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_closures19392026/10/04 19:29:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.259285ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19402026/10/04 19:29:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.937924ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19412026/10/04 19:29:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=749.510779ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19422026/10/04 19:29:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.64933403s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1943--- PASS: TestClientErrorHandling (0.00s)1944 --- PASS: TestClientErrorHandling/InvalidStorePath (0.21s)1945 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.31s)1946 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.61s)1947PASS19482026-10-04 19:29:11.827 UTC [128] LOG: received smart shutdown request19492026-10-04 19:29:11.831 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 119502026-10-04 19:29:11.845 UTC [133] LOG: shutting down19512026-10-04 19:29:11.845 UTC [133] LOG: checkpoint starting: shutdown immediate19522026-10-04 19:29:12.697 UTC [133] LOG: checkpoint complete: wrote 11035 buffers (67.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.187 s, sync=0.637 s, total=0.853 s; sync files=29992, longest=0.002 s, average=0.001 s; distance=414736 kB, estimate=414736 kB; lsn=0/1AC6A0C8, redo lsn=0/1AC6A0C819532026-10-04 19:29:12.775 UTC [128] LOG: database system is shut down1954Running OIDC tests...1955=== RUN TestAudienceForIssuer1956=== PAUSE TestAudienceForIssuer1957=== RUN TestGlobMatch1958=== PAUSE TestGlobMatch1959=== RUN TestValidateToken_ValidToken1960=== PAUSE TestValidateToken_ValidToken1961=== RUN TestValidateToken_WrongAudience1962=== PAUSE TestValidateToken_WrongAudience1963=== RUN TestValidateToken_Expired1964=== PAUSE TestValidateToken_Expired1965=== RUN TestValidateToken_BoundClaimsMismatch1966=== PAUSE TestValidateToken_BoundClaimsMismatch1967=== RUN TestValidateToken_BoundSubjectMismatch1968=== PAUSE TestValidateToken_BoundSubjectMismatch1969=== RUN TestValidateToken_MultipleProviders1970=== PAUSE TestValidateToken_MultipleProviders1971=== RUN TestValidateToken_NoMatchingProvider1972=== PAUSE TestValidateToken_NoMatchingProvider1973=== RUN TestValidateToken_KubernetesServiceAccount1974=== PAUSE TestValidateToken_KubernetesServiceAccount1975=== RUN TestNewValidator_KubernetesRequiresCA1976=== PAUSE TestNewValidator_KubernetesRequiresCA1977=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1978=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1979=== RUN TestPins_ReservedForMatchingRule1980=== PAUSE TestPins_ReservedForMatchingRule1981=== RUN TestPins_TopLevelShorthand1982=== PAUSE TestPins_TopLevelShorthand1983=== RUN TestPins_ConfigValidation1984=== PAUSE TestPins_ConfigValidation1985=== RUN TestScopes_LegacyProviderDefaultsToWrite1986=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1987=== RUN TestScopes_Rules1988=== PAUSE TestScopes_Rules1989=== RUN TestScopes_ConfigValidation1990=== PAUSE TestScopes_ConfigValidation1991=== CONT TestAudienceForIssuer1992=== CONT TestPins_ConfigValidation1993--- PASS: TestAudienceForIssuer (0.00s)1994=== CONT TestValidateToken_NoMatchingProvider1995=== CONT TestValidateToken_KubernetesServiceAccount1996=== CONT TestScopes_Rules1997=== CONT TestScopes_ConfigValidation1998=== CONT TestValidateToken_Expired1999=== CONT TestValidateToken_MultipleProviders2000=== CONT TestValidateToken_BoundSubjectMismatch2001=== CONT TestValidateToken_BoundClaimsMismatch2002=== CONT TestScopes_LegacyProviderDefaultsToWrite2003--- PASS: TestPins_ConfigValidation (0.00s)2004=== CONT TestValidateToken_ValidToken2005=== CONT TestValidateToken_WrongAudience2006=== CONT TestGlobMatch2007=== RUN TestGlobMatch/foo_foo2008=== PAUSE TestGlobMatch/foo_foo2009=== CONT TestPins_ReservedForMatchingRule2010=== CONT TestPins_TopLevelShorthand2011=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2012=== CONT TestNewValidator_KubernetesRequiresCA2013--- PASS: TestScopes_ConfigValidation (0.00s)2014=== RUN TestGlobMatch/foo_bar2015=== PAUSE TestGlobMatch/foo_bar2016=== RUN TestGlobMatch/*_2017=== PAUSE TestGlobMatch/*_2018=== RUN TestGlobMatch/*_anything2019=== PAUSE TestGlobMatch/*_anything2020=== RUN TestGlobMatch/foo*_foo2021=== PAUSE TestGlobMatch/foo*_foo2022=== RUN TestGlobMatch/foo*_foobar2023=== PAUSE TestGlobMatch/foo*_foobar2024=== RUN TestGlobMatch/foo*_bar2025=== PAUSE TestGlobMatch/foo*_bar2026=== RUN TestGlobMatch/*bar_bar2027=== PAUSE TestGlobMatch/*bar_bar2028=== RUN TestGlobMatch/*bar_foobar2029=== PAUSE TestGlobMatch/*bar_foobar2030=== RUN TestGlobMatch/*bar_foo2031=== PAUSE TestGlobMatch/*bar_foo2032=== RUN TestGlobMatch/foo*bar_foobar2033=== PAUSE TestGlobMatch/foo*bar_foobar2034=== RUN TestGlobMatch/foo*bar_foo123bar2035=== PAUSE TestGlobMatch/foo*bar_foo123bar2036=== RUN TestGlobMatch/foo*bar_foobarbaz2037=== PAUSE TestGlobMatch/foo*bar_foobarbaz2038=== RUN TestGlobMatch/*/*_foo/bar2039=== PAUSE TestGlobMatch/*/*_foo/bar2040=== RUN TestGlobMatch/*/*_foo2041=== PAUSE TestGlobMatch/*/*_foo2042=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2043=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2044=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02045=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02046=== RUN TestGlobMatch/refs/*/main_refs/heads/main2047=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2048=== RUN TestGlobMatch/fo?_foo2049=== PAUSE TestGlobMatch/fo?_foo2050=== RUN TestGlobMatch/fo?_fo2051=== PAUSE TestGlobMatch/fo?_fo2052=== RUN TestGlobMatch/fo?_fooo2053=== PAUSE TestGlobMatch/fo?_fooo2054=== RUN TestGlobMatch/?oo_foo2055=== PAUSE TestGlobMatch/?oo_foo2056=== RUN TestGlobMatch/?oo_boo2057=== PAUSE TestGlobMatch/?oo_boo2058=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2059=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2060=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2061=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2062=== CONT TestGlobMatch/foo_foo2063=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2064=== CONT TestGlobMatch/?oo_boo2065=== CONT TestGlobMatch/?oo_foo2066=== CONT TestGlobMatch/fo?_fooo2067=== CONT TestGlobMatch/fo?_fo2068=== CONT TestGlobMatch/fo?_foo2069=== CONT TestGlobMatch/refs/*/main_refs/heads/main2070=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02071=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2072=== CONT TestGlobMatch/*/*_foo2073=== CONT TestGlobMatch/*/*_foo/bar2074=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2075=== CONT TestGlobMatch/*_anything2076=== CONT TestGlobMatch/*_2077=== CONT TestGlobMatch/foo_bar2078=== CONT TestGlobMatch/foo*bar_foobarbaz2079=== CONT TestGlobMatch/foo*bar_foo123bar2080=== CONT TestGlobMatch/foo*bar_foobar2081=== CONT TestGlobMatch/*bar_foo2082=== CONT TestGlobMatch/*bar_foobar2083=== CONT TestGlobMatch/*bar_bar2084=== CONT TestGlobMatch/foo*_bar2085=== CONT TestGlobMatch/foo*_foobar2086=== CONT TestGlobMatch/foo*_foo2087--- PASS: TestGlobMatch (0.00s)2088 --- PASS: TestGlobMatch/foo_foo (0.00s)2089 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2090 --- PASS: TestGlobMatch/?oo_boo (0.00s)2091 --- PASS: TestGlobMatch/?oo_foo (0.00s)2092 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2093 --- PASS: TestGlobMatch/fo?_fo (0.00s)2094 --- PASS: TestGlobMatch/fo?_foo (0.00s)2095 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2096 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2097 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2098 --- PASS: TestGlobMatch/*/*_foo (0.00s)2099 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2100 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2101 --- PASS: TestGlobMatch/*_anything (0.00s)2102 --- PASS: TestGlobMatch/*_ (0.00s)2103 --- PASS: TestGlobMatch/foo_bar (0.00s)2104 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2105 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2106 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2107 --- PASS: TestGlobMatch/*bar_foo (0.00s)2108 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2109 --- PASS: TestGlobMatch/*bar_bar (0.00s)2110 --- PASS: TestGlobMatch/foo*_bar (0.00s)2111 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2112 --- PASS: TestGlobMatch/foo*_foo (0.00s)21132026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43385/oidc21142026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38035/oidc2115--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)2116--- PASS: TestValidateToken_WrongAudience (0.05s)21172026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43043/oidc2118--- PASS: TestScopes_Rules (0.07s)21192026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44215/oidc21202026/10/04 19:29:14 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45179/oidc2121--- PASS: TestValidateToken_NoMatchingProvider (0.11s)2122--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)21232026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42711/oidc2124--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)21252026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43247/oidc2126--- PASS: TestValidateToken_Expired (0.15s)21272026/10/04 19:29:14 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:367512128--- PASS: TestValidateToken_KubernetesServiceAccount (0.18s)21292026/10/04 19:29:14 http: TLS handshake error from 127.0.0.1:59186: remote error: tls: bad certificate2130--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)21312026/10/04 19:29:14 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321322026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45535/oidc2133--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.23s)2134--- PASS: TestValidateToken_ValidToken (0.23s)21352026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33845/oidc21362026/10/04 19:29:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38675/oidc2137--- PASS: TestPins_TopLevelShorthand (0.25s)2138--- PASS: TestPins_ReservedForMatchingRule (0.25s)21392026/10/04 19:29:14 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40367/oidc21402026/10/04 19:29:14 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:33641/oidc2141--- PASS: TestValidateToken_MultipleProviders (0.29s)2142PASS2143Running hook tests...2144=== RUN TestSendPathsEmpty2145=== PAUSE TestSendPathsEmpty2146=== RUN TestQueueEnqueueAndFetch2147=== PAUSE TestQueueEnqueueAndFetch2148=== RUN TestQueueDeduplication2149=== PAUSE TestQueueDeduplication2150=== RUN TestQueueRemove2151=== PAUSE TestQueueRemove2152=== RUN TestQueueFetchBatchLimit2153=== PAUSE TestQueueFetchBatchLimit2154=== RUN TestQueueRetryMovesToBack2155=== PAUSE TestQueueRetryMovesToBack2156=== RUN TestQueueFetchRemoveLifecycle2157=== PAUSE TestQueueFetchRemoveLifecycle2158=== RUN TestQueueConcurrentWriters2159=== PAUSE TestQueueConcurrentWriters2160=== RUN TestQueueRemoveLargeClosure2161=== PAUSE TestQueueRemoveLargeClosure2162=== RUN TestServerClientIntegration2163=== PAUSE TestServerClientIntegration2164=== RUN TestServerQueueError2165=== PAUSE TestServerQueueError2166=== RUN TestGetListenerSocketActivation2167 server_test.go:210: === RUN TestGetListenerSocketActivation2168 --- PASS: TestGetListenerSocketActivation (0.00s)2169 PASS2170 2171--- PASS: TestGetListenerSocketActivation (0.01s)2172=== RUN TestDrainIsolatesPoisonPath2173=== PAUSE TestDrainIsolatesPoisonPath2174=== RUN TestRunNotBlockedByPoisonHead2175=== PAUSE TestRunNotBlockedByPoisonHead2176=== RUN TestDrainGivesUpWhenServerDown2177=== PAUSE TestDrainGivesUpWhenServerDown2178=== RUN TestFailedPathPrunedByLaterClosure2179=== PAUSE TestFailedPathPrunedByLaterClosure2180=== RUN TestWorkerUploadsAndRemoves2181=== PAUSE TestWorkerUploadsAndRemoves2182=== RUN TestWorkerSkipsGCdPaths2183=== PAUSE TestWorkerSkipsGCdPaths2184=== RUN TestWorkerPrunesClosureDeps2185=== PAUSE TestWorkerPrunesClosureDeps2186=== RUN TestDrainTimeout2187=== PAUSE TestDrainTimeout2188=== CONT TestSendPathsEmpty2189=== CONT TestRunNotBlockedByPoisonHead2190=== CONT TestQueueFetchRemoveLifecycle2191--- PASS: TestSendPathsEmpty (0.00s)2192=== CONT TestDrainIsolatesPoisonPath2193=== CONT TestWorkerSkipsGCdPaths2194=== CONT TestQueueRetryMovesToBack2195=== CONT TestQueueFetchBatchLimit2196=== CONT TestDrainTimeout2197=== CONT TestQueueRemove2198=== CONT TestQueueDeduplication2199=== CONT TestWorkerPrunesClosureDeps2200=== CONT TestQueueEnqueueAndFetch2201=== CONT TestServerClientIntegration2202=== CONT TestQueueRemoveLargeClosure2203=== CONT TestServerQueueError2204=== CONT TestFailedPathPrunedByLaterClosure2205=== CONT TestWorkerUploadsAndRemoves2206=== CONT TestDrainGivesUpWhenServerDown2207=== CONT TestQueueConcurrentWriters22082026/10/04 19:29:14 ERROR Failed to queue paths error="permission denied" count=12209--- PASS: TestServerClientIntegration (0.00s)2210--- PASS: TestServerQueueError (0.00s)22112026/10/04 19:29:14 INFO Uploading batch count=422122026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=422132026/10/04 19:29:14 INFO Uploading batch count=122142026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=122152026/10/04 19:29:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2531971928/002/bbb22162026/10/04 19:29:14 INFO Uploading batch count=222172026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=222182026/10/04 19:29:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2202181465/002/a22192026/10/04 19:29:14 INFO Uploading batch count=122202026/10/04 19:29:14 INFO Upload queue status pending=222212026/10/04 19:29:14 INFO Uploading batch count=12222--- PASS: TestQueueFetchBatchLimit (0.01s)22232026/10/04 19:29:14 INFO Upload queue status pending=222242026/10/04 19:29:14 INFO Upload queue status pending=322252026/10/04 19:29:14 INFO Uploading batch count=222262026/10/04 19:29:14 INFO Uploading batch count=122272026/10/04 19:29:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2202181465/002/b22282026/10/04 19:29:14 INFO Uploading batch count=122292026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=122302026/10/04 19:29:14 INFO Uploading batch count=122312026/10/04 19:29:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4133012366/002/nonexistent2232--- PASS: TestQueueRetryMovesToBack (0.01s)22332026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=122342026/10/04 19:29:14 INFO Upload queue status pending=22235--- PASS: TestQueueEnqueueAndFetch (0.01s)22362026/10/04 19:29:14 INFO Uploading batch count=12237--- PASS: TestQueueRemove (0.01s)22382026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=122392026/10/04 19:29:14 INFO Uploading batch count=122402026/10/04 19:29:14 INFO Uploading batch count=22241--- PASS: TestQueueDeduplication (0.01s)22422026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=222432026/10/04 19:29:14 INFO Uploading batch count=22244--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22452026/10/04 19:29:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2202181465/002/c22462026/10/04 19:29:14 INFO Uploading batch count=122472026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=122482026/10/04 19:29:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2202181465/002/d22492026/10/04 19:29:14 ERROR Drain finished with paths left in queue remaining=122502026/10/04 19:29:14 INFO Uploading batch count=222512026/10/04 19:29:14 ERROR Upload failed error="upload failed" count=222522026/10/04 19:29:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2202181465/002/e2253--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22542026/10/04 19:29:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2202181465/002/f22552026/10/04 19:29:14 ERROR Drain finished with paths left in queue remaining=102256--- PASS: TestDrainIsolatesPoisonPath (0.02s)2257--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2258--- PASS: TestWorkerPrunesClosureDeps (0.03s)2259--- PASS: TestWorkerSkipsGCdPaths (0.03s)2260--- PASS: TestWorkerUploadsAndRemoves (0.03s)2261--- PASS: TestQueueRemoveLargeClosure (0.14s)2262--- PASS: TestQueueConcurrentWriters (0.15s)22632026/10/04 19:29:14 ERROR Upload failed error="context deadline exceeded" count=222642026/10/04 19:29:14 ERROR Drain finished with paths left in queue remaining=42265--- PASS: TestDrainTimeout (0.21s)22662026/10/04 19:29:15 INFO Uploading batch count=122672026/10/04 19:29:15 INFO Uploading batch count=122682026/10/04 19:29:15 INFO Uploading batch count=122692026/10/04 19:29:15 ERROR Upload failed error="upload failed" count=122702026/10/04 19:29:15 INFO Uploading batch count=122712026/10/04 19:29:15 ERROR Upload failed error="upload failed" count=122722026/10/04 19:29:15 INFO Uploading batch count=122732026/10/04 19:29:15 ERROR Upload failed error="upload failed" count=122742026/10/04 19:29:15 INFO Uploading batch count=122752026/10/04 19:29:15 ERROR Upload failed error="upload failed" count=122762026/10/04 19:29:15 ERROR Drain finished with paths left in queue remaining=12277--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2278PASS