niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #343
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestShellSplit97=== CONT TestEncodeNixBase32WithRealHash98=== CONT TestDoWithRetry_BodyReplayedViaGetBody99=== CONT TestResolveStorePath100=== CONT TestSetClientTLSErrors101=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess102=== CONT TestRateLimiterFeedback103=== RUN TestRateLimiterFeedback/429_enables_limiter104=== CONT TestScriptTokenEmptyCommand105=== PAUSE TestRateLimiterFeedback/429_enables_limiter106=== CONT TestStaticToken107=== RUN TestRateLimiterFeedback/503_enables_limiter108=== CONT TestDumpPathWriterError109=== CONT TestPathInfoCACompatibility110=== CONT TestScriptTokenScriptFails111=== CONT TestParsePathInfoJSONMultiplePaths112=== CONT TestParsePathInfoJSON113=== CONT TestPathInfoHashCompatibility114=== CONT TestScriptTokenBadJSON115=== CONT TestGetStorePathHash116=== CONT TestScriptTokenEmptyToken117=== CONT TestScriptTokenCachesUntilRefresh1182026/10/01 10:41:26 WARN Rate limiter enabled after throttle name=server-test rate=5119=== CONT TestScriptTokenNoExpiryRerunsEveryCall120=== CONT TestConvertHashToNix32121=== CONT TestFileTokenEmpty122=== CONT TestFilterOversizedClosures123=== CONT TestFileTokenMissing124=== CONT TestPartSizeForNAR125--- PASS: TestShellSplit (0.00s)126=== CONT TestFileTokenReadsAndCaches127=== CONT TestUploadMultipart_PartsInParallel128=== PAUSE TestRateLimiterFeedback/503_enables_limiter129=== RUN TestPathInfoCACompatibility/null_ca_field130=== RUN TestParsePathInfoJSON/Nix_format131--- PASS: TestEncodeNixBase32WithRealHash (0.00s)132--- PASS: TestScriptTokenEmptyCommand (0.00s)133--- PASS: TestStaticToken (0.00s)134--- PASS: TestResolveStorePath (0.00s)135=== PAUSE TestParsePathInfoJSON/Nix_format136=== RUN TestParsePathInfoJSON/Lix_format137=== PAUSE TestParsePathInfoJSON/Lix_format138=== RUN TestParsePathInfoJSON/empty_input139=== PAUSE TestParsePathInfoJSON/empty_input140=== RUN TestParsePathInfoJSON/whitespace_only141=== PAUSE TestParsePathInfoJSON/whitespace_only142=== RUN TestParsePathInfoJSON/invalid_JSON143=== PAUSE TestParsePathInfoJSON/invalid_JSON144=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)145=== RUN TestFilterOversizedClosures/no_limit_keeps_everything146=== RUN TestGetStorePathHash/valid_store_path147=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== RUN TestConvertHashToNix32/SRI_format_to_Nix32149=== CONT TestStreamPushRequestLine150=== CONT TestEncodeNixBase32151=== RUN TestPartSizeForNAR/zero_stays_at_minimum152--- PASS: TestScriptTokenScriptFails (0.00s)153=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum154--- PASS: TestFileTokenMissing (0.00s)155=== CONT TestStreamPushBatchesUnderLoad156--- PASS: TestFileTokenEmpty (0.00s)157=== CONT TestSetClientTLS158--- PASS: TestScriptTokenEmptyToken (0.00s)159=== CONT TestStreamPushGivesUpOnDeadServer160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1612026/10/01 10:41:26 ERROR Upload failed error="connection refused" count=20162=== PAUSE TestPathInfoCACompatibility/null_ca_field1632026/10/01 10:41:26 ERROR Server seems unavailable, giving up on batch untried=17164=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything165--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)166=== CONT TestClientSignaturesByStorePath1672026/10/01 10:41:26 WARN Rate limiter enabled after throttle name=server-test rate=5168=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter169=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1702026/10/01 10:41:26 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37099171=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped172=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter173=== RUN TestPartSizeForNAR/small_stays_at_minimum174=== RUN TestEncodeNixBase32/test_string_hash175=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter176=== CONT TestStreamPushReportsEveryPath177=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter178=== PAUSE TestPartSizeForNAR/small_stays_at_minimum179=== PAUSE TestEncodeNixBase32/test_string_hash180=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum181=== RUN TestEncodeNixBase32/empty_input182=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum183=== CONT TestSetClientTLSDoesNotMutateDefaultTransport184--- PASS: TestClientSignaturesByStorePath (0.00s)185--- PASS: TestFileTokenReadsAndCaches (0.01s)186--- PASS: TestScriptTokenBadJSON (0.01s)187=== CONT TestStreamPushReportsSignatures188=== CONT TestStreamPushIsolatesFailures189=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32190=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths191=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped1922026/10/01 10:41:26 ERROR Upload failed error=boom count=11932026/10/01 10:41:26 WARN Rate limiter backed off name=server-test rate=51942026/10/01 10:41:26 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37099195=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1962026/10/01 10:41:26 ERROR Upload failed error="bad path" count=3197=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon198=== RUN TestSetClientTLSErrors/missing_cert_file199=== PAUSE TestGetStorePathHash/valid_store_path200=== CONT TestDumpPathSingleFile201=== RUN TestPathInfoCACompatibility/old_string_format_-_text202=== CONT TestCaseHackSuffix203=== CONT TestRegisterUploadedObjectReusesConnections2042026/10/01 10:41:26 ERROR Upload failed error=boom count=1205=== PAUSE TestSetClientTLSErrors/missing_cert_file206=== RUN TestSetClientTLSErrors/missing_key_file207=== PAUSE TestSetClientTLSErrors/missing_key_file208=== RUN TestSetClientTLSErrors/missing_ca_file209=== PAUSE TestSetClientTLSErrors/missing_ca_file210=== RUN TestSetClientTLSErrors/invalid_ca_file211=== PAUSE TestSetClientTLSErrors/invalid_ca_file212=== CONT TestParsePathInfoJSON/Nix_format213=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts214=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts215=== RUN TestPartSizeForNAR/1_TiB216=== PAUSE TestPartSizeForNAR/1_TiB217=== RUN TestPartSizeForNAR/5_TiB_S3_max_object218=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object219=== RUN TestPartSizeForNAR/capped_at_5_GiB220=== PAUSE TestPartSizeForNAR/capped_at_5_GiB221=== CONT TestParsePathInfoJSON/empty_input222=== CONT TestParsePathInfoJSON/Lix_format223=== CONT TestRateLimiterFeedback/429_enables_limiter224=== CONT TestDumpPathMatchesNix225=== CONT TestParsePathInfoJSON/whitespace_only226=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2272026/10/01 10:41:26 WARN Rate limiter enabled after throttle name=server-test rate=52282026/10/01 10:41:26 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:402092292026/10/01 10:41:26 WARN Rate limiter backed off name=server-test rate=5230=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter231=== CONT TestRateLimiterFeedback/503_enables_limiter232=== CONT TestSetClientTLSErrors/missing_cert_file233=== CONT TestPartSizeForNAR/zero_stays_at_minimum234=== CONT TestPartSizeForNAR/5_TiB_S3_max_object235=== CONT TestSetClientTLSErrors/invalid_ca_file236=== CONT TestSetClientTLSErrors/missing_ca_file237=== CONT TestSetClientTLSErrors/missing_key_file238=== CONT TestPartSizeForNAR/capped_at_5_GiB239=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts240=== CONT TestPartSizeForNAR/1_TiB241=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum242=== CONT TestPartSizeForNAR/small_stays_at_minimum2432026/10/01 10:41:26 WARN Rate limiter enabled after throttle name=server-test rate=52442026/10/01 10:41:26 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:446772452026/10/01 10:41:26 WARN Rate limiter backed off name=server-test rate=5246=== CONT TestShellSplitErrors247=== RUN TestConvertHashToNix32/already_Nix32_format248=== PAUSE TestConvertHashToNix32/already_Nix32_format249=== RUN TestConvertHashToNix32/invalid_format250=== PAUSE TestConvertHashToNix32/invalid_format251=== CONT TestConvertHashToNix32/SRI_format_to_Nix32252=== CONT TestConvertHashToNix32/invalid_format253=== RUN TestFilterOversizedClosures/all_closures_skipped254=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths255=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text256=== PAUSE TestEncodeNixBase32/empty_input257=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI258=== RUN TestGetStorePathHash/basename_without_hyphen_should_error259=== CONT TestUploadMultipart_SupersededByPeer260--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)261=== CONT TestParsePathInfoJSON/invalid_JSON262=== RUN TestSetClientTLS/rejects_connection_without_client_cert263=== CONT TestConvertHashToNix32/already_Nix32_format264=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive265=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error266=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error267=== RUN TestUploadMultipart_SupersededByPeer/exists268=== PAUSE TestUploadMultipart_SupersededByPeer/exists269=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert270=== CONT TestEncodeNixBase32/test_string_hash271=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA272=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA273=== CONT TestEncodeNixBase32/empty_input274=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths275=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths276=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI277=== PAUSE TestFilterOversizedClosures/all_closures_skipped278=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== CONT TestFilterOversizedClosures/all_closures_skipped2802026/10/01 10:41:26 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=50281=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512282--- PASS: TestStreamPushReportsEveryPath (0.03s)283=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error284=== RUN TestUploadMultipart_SupersededByPeer/missing285=== PAUSE TestUploadMultipart_SupersededByPeer/missing286=== CONT TestUploadMultipart_SupersededByPeer/exists287=== CONT TestUploadMultipart_SupersededByPeer/missing288=== RUN TestSetClientTLS/preserves_debug_logging_transport289=== PAUSE TestSetClientTLS/preserves_debug_logging_transport290=== CONT TestSetClientTLS/rejects_connection_without_client_cert291=== CONT TestFilterOversizedClosures/no_limit_keeps_everything292=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA293=== CONT TestSetClientTLS/preserves_debug_logging_transport294=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295=== RUN TestPathInfoCACompatibility/new_structured_format_-_text296=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text297=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method298=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method299=== CONT TestPathInfoCACompatibility/null_ca_field300=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)301=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512302=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped303=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3042026/10/01 10:41:26 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=2000305=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI306--- PASS: TestDoServerRequestAttachesToken (0.04s)307=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error308=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive309=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method310=== CONT TestPathInfoCACompatibility/old_string_format_-_text311=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon312--- PASS: TestStreamPushIsolatesFailures (0.00s)313=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error314=== CONT TestGetStorePathHash/valid_store_path315=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error316=== CONT TestGetStorePathHash/basename_without_hyphen_should_error317=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error318--- PASS: TestStreamPushReportsSignatures (0.00s)319--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)320--- PASS: TestShellSplitErrors (0.00s)321--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)322--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)323--- PASS: TestFilterOversizedClosures (0.04s)324 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)325 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)326 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)327--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)328 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)329 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)330--- PASS: TestEncodeNixBase32 (0.03s)331 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)332 --- PASS: TestEncodeNixBase32/empty_input (0.00s)333--- PASS: TestPathInfoCACompatibility (0.04s)334 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)335 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)336 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)337 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)338 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)339--- PASS: TestPartSizeForNAR (0.03s)340 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)341 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)342 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)343 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)344 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)345 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)346 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)347--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)348 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)349 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)350--- PASS: TestParsePathInfoJSON (0.00s)351 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)352 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)353 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)354 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)355 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)356--- PASS: TestPathInfoHashCompatibility (0.04s)357 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)358 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)359 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)360 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)361--- PASS: TestGetStorePathHash (0.04s)362 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)363 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)364 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)365 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)366--- PASS: TestConvertHashToNix32 (0.04s)367 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)368 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)369 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)370--- 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)375--- PASS: TestRateLimiterFeedback (0.01s)376 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3802026/10/01 10:41:26 http: TLS handshake error from 127.0.0.1:43112: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.04s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)385--- PASS: TestStreamPushRequestLine (0.05s)386--- PASS: TestDumpPathSingleFile (0.03s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)388--- PASS: TestDumpPathWriterError (0.07s)389--- PASS: TestCaseHackSuffix (0.04s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.09s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)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/postgres3743779375/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/postgres3743779375/data -l logfile start422423/build/postgres3743779375:5432 - no response4242026-10-01 10:41:27.959 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:41:27.960 UTC [129] LOG: listening on Unix socket "/build/postgres3743779375/.s.PGSQL.5432"4262026-10-01 10:41:27.964 UTC [136] LOG: database system was shut down at 2026-10-01 10:41:27 UTC4272026-10-01 10:41:27.969 UTC [129] LOG: database system is ready to accept connections428/build/postgres3743779375:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestConnectWaitsForAPeerMigration470=== PAUSE TestConnectWaitsForAPeerMigration471=== RUN TestLeadElectsOneAndHandsOver472=== PAUSE TestLeadElectsOneAndHandsOver473=== RUN TestLeadIncumbentWinsAfterRestart4742026/10/01 10:41:28 INFO lead: acquired remote=192.0.2.1:12344752026/10/01 10:41:29 INFO lead: released remote=192.0.2.1:12344762026/10/01 10:41:29 INFO lead: acquired remote=192.0.2.1:12344772026/10/01 10:41:29 INFO lead: released remote=192.0.2.1:1234478--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)479=== RUN TestLeadEndsOnShutdown480=== PAUSE TestLeadEndsOnShutdown481=== RUN TestGCAdvisoryLockBlocksConcurrentRun482=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun483=== RUN TestGCBugBareHashReferences484=== PAUSE TestGCBugBareHashReferences485=== RUN TestGCMetrics486=== PAUSE TestGCMetrics487=== RUN TestPushDedupSurvivesConcurrentGC488=== PAUSE TestPushDedupSurvivesConcurrentGC489=== RUN TestDeduplicatedObjectsRecordedAsPending490=== PAUSE TestDeduplicatedObjectsRecordedAsPending491=== RUN TestGCSweepSkipsPendingObjects492=== PAUSE TestGCSweepSkipsPendingObjects493=== RUN TestTombstonedObjectOfferedWithoutWaiting494=== PAUSE TestTombstonedObjectOfferedWithoutWaiting495=== RUN TestGCSweepDeliversEachKeyOnce496=== PAUSE TestGCSweepDeliversEachKeyOnce497=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection498=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection499=== RUN TestForceGCDuringPushOffersSweptObject500=== PAUSE TestForceGCDuringPushOffersSweptObject501=== RUN TestFailedS3DeleteKeepsTombstone502=== PAUSE TestFailedS3DeleteKeepsTombstone503=== RUN TestSweepSkipsRowsLockedByPush504=== PAUSE TestSweepSkipsRowsLockedByPush505=== RUN TestRegisterCompletedObjectNeedsPendingRow506=== PAUSE TestRegisterCompletedObjectNeedsPendingRow507=== RUN TestGetExistingObjectsLocksRows508=== PAUSE TestGetExistingObjectsLocksRows509=== RUN TestSweepRechecksPendingAfterLocking510=== PAUSE TestSweepRechecksPendingAfterLocking511=== RUN TestPushWaitsForSweepHoldingRow512=== PAUSE TestPushWaitsForSweepHoldingRow513=== RUN TestCommitRacingPendingCleanupKeepsObjects514=== PAUSE TestCommitRacingPendingCleanupKeepsObjects515=== RUN TestGCEndsOnShutdown516=== PAUSE TestGCEndsOnShutdown517=== RUN TestGCTaskStore_StartNew518=== PAUSE TestGCTaskStore_StartNew519=== RUN TestGCTaskStore_DeduplicateSameParams520=== PAUSE TestGCTaskStore_DeduplicateSameParams521=== RUN TestGCTaskStore_ConflictDifferentParams522=== PAUSE TestGCTaskStore_ConflictDifferentParams523=== RUN TestGCTaskStore_GetEmpty524=== PAUSE TestGCTaskStore_GetEmpty525=== RUN TestGCTaskStore_GetReturnsLatest526=== PAUSE TestGCTaskStore_GetReturnsLatest527=== RUN TestGCTaskStore_CompletedAllowsNewTask528=== PAUSE TestGCTaskStore_CompletedAllowsNewTask529=== RUN TestGCTaskStore_PhaseUpdates530=== PAUSE TestGCTaskStore_PhaseUpdates531=== RUN TestGCTaskStore_Fail532=== PAUSE TestGCTaskStore_Fail533=== RUN TestGracefulShutdownDrainsInflight534=== PAUSE TestGracefulShutdownDrainsInflight535=== RUN TestService_healthCheckHandler536=== PAUSE TestService_healthCheckHandler537=== RUN TestService_readinessHandler538=== PAUSE TestService_readinessHandler539=== RUN TestGenerateLandingPage540=== PAUSE TestGenerateLandingPage541=== RUN TestCacheConfigHandlerMaxNarSize542=== PAUSE TestCacheConfigHandlerMaxNarSize543=== RUN TestCreatePendingClosureRejectsOversizedNAR544=== PAUSE TestCreatePendingClosureRejectsOversizedNAR545=== RUN TestNARDeduplicationMetadataUploadBug546=== PAUSE TestNARDeduplicationMetadataUploadBug547=== RUN TestMetricsInventory548=== PAUSE TestMetricsInventory549=== RUN TestService_NativeMTLS550=== PAUSE TestService_NativeMTLS551=== RUN TestServerTLSConfig552=== PAUSE TestServerTLSConfig553=== RUN TestMultipartCleanup554=== PAUSE TestMultipartCleanup555=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded556=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded557=== RUN TestPendingCleanupUsesOneCutoff558=== PAUSE TestPendingCleanupUsesOneCutoff559=== RUN TestObjectStatsTrigger560=== PAUSE TestObjectStatsTrigger561=== RUN TestOrphanedObjectsGC562=== PAUSE TestOrphanedObjectsGC563=== RUN TestOrphanedObjectsGCStressTest564=== PAUSE TestOrphanedObjectsGCStressTest565=== RUN TestCreatePin_ReservedPins566=== PAUSE TestCreatePin_ReservedPins567=== RUN TestPresentReportsOnlyClosureRoots568=== PAUSE TestPresentReportsOnlyClosureRoots569=== RUN TestPresentNotReportedWhileGCDeletesClosure570=== PAUSE TestPresentNotReportedWhileGCDeletesClosure571=== RUN TestParseSingleRange572=== PAUSE TestParseSingleRange573=== RUN TestProxyHeadersOnlyTrustedOnSocket574=== PAUSE TestProxyHeadersOnlyTrustedOnSocket575=== RUN TestIsValidCachePath576=== PAUSE TestIsValidCachePath577=== RUN TestReadProxyNarinfo578=== PAUSE TestReadProxyNarinfo579=== RUN TestReadProxyNarinfoAlreadyDecompressed580=== PAUSE TestReadProxyNarinfoAlreadyDecompressed581=== RUN TestReadProxyNarStreaming582=== PAUSE TestReadProxyNarStreaming583=== RUN TestReadProxy404584=== PAUSE TestReadProxy404585=== RUN TestReadProxyInvalidPath586=== PAUSE TestReadProxyInvalidPath587=== RUN TestReadProxyHead588=== PAUSE TestReadProxyHead589=== RUN TestReadProxyOutlastsServerWriteTimeout590=== PAUSE TestReadProxyOutlastsServerWriteTimeout591=== RUN TestReadProxyConditionalGet592=== PAUSE TestReadProxyConditionalGet593=== RUN TestReadProxyRootRedirectsToIndexHTML594=== PAUSE TestReadProxyRootRedirectsToIndexHTML595=== RUN TestReadProxyDisabled596=== PAUSE TestReadProxyDisabled597=== RUN TestReadRedirectNar598=== PAUSE TestReadRedirectNar599=== RUN TestReadRedirectKeepsNarinfoProxied600=== PAUSE TestReadRedirectKeepsNarinfoProxied601=== RUN TestReadProxyRangeRequest602=== PAUSE TestReadProxyRangeRequest603=== RUN TestReadRedirectUsesPublicS3URL604=== PAUSE TestReadRedirectUsesPublicS3URL605=== RUN TestPush_OverlappingRootsStoreOneRowPerKey606=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey607=== RUN TestPush_CompleteCommitsEveryRoot608=== PAUSE TestPush_CompleteCommitsEveryRoot609=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit610=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit611=== RUN TestPush_RejectsBadRequests612=== PAUSE TestPush_RejectsBadRequests613=== RUN TestPush_SignsNarinfosOfItsPendingObjects614=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects615=== RUN TestRedundantMultipartUpload616=== PAUSE TestRedundantMultipartUpload617=== RUN TestCompleteMultipartUpload_ErrorButObjectExists618=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists619=== RUN TestCompletedNarNotReofferedAcrossClosures620=== PAUSE TestCompletedNarNotReofferedAcrossClosures621=== RUN TestPresignedUploadRegisteredBeforeCommit622=== PAUSE TestPresignedUploadRegisteredBeforeCommit623=== RUN TestService_Rustfstest624=== PAUSE TestService_Rustfstest625=== RUN TestParseSize626=== PAUSE TestParseSize627=== RUN TestSkippedUploadsHandler628=== PAUSE TestSkippedUploadsHandler629=== RUN TestSystemdListenerNotActivated630--- PASS: TestSystemdListenerNotActivated (0.00s)631=== RUN TestWatchdogBeatsWhenHealthy632--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)633=== RUN TestWatchdogSkipsWhenUnhealthy6342026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 10:41:29 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"644--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)645=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle646=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle647=== RUN TestProxyWriteTimeout648=== PAUSE TestProxyWriteTimeout649=== RUN TestPendingClosureWriteTimeout650=== PAUSE TestPendingClosureWriteTimeout651=== RUN TestIsValidUploadKey652=== PAUSE TestIsValidUploadKey653=== RUN TestUploadHandlersRejectInvalidKeys654=== PAUSE TestUploadHandlersRejectInvalidKeys655=== RUN TestUploadHandlersRejectOversizedBody656=== PAUSE TestUploadHandlersRejectOversizedBody657=== RUN TestService_cleanupPendingClosuresHandler658=== PAUSE TestService_cleanupPendingClosuresHandler659=== RUN TestService_createPendingClosureHandler660=== PAUSE TestService_createPendingClosureHandler661=== RUN TestService_verifyS3Integrity662=== PAUSE TestService_verifyS3Integrity663=== RUN TestCompleteMultipartUnregistered664=== PAUSE TestCompleteMultipartUnregistered665=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT666=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT667=== CONT TestService_AuthMiddleware668=== CONT TestReadProxyConditionalGet669=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT670=== CONT TestCompleteMultipartUnregistered671=== CONT TestService_verifyS3Integrity672=== CONT TestService_createPendingClosureHandler673=== CONT TestService_cleanupPendingClosuresHandler674=== CONT TestUploadHandlersRejectOversizedBody675=== CONT TestUploadHandlersRejectInvalidKeys676=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info677=== CONT TestIsValidUploadKey678=== RUN TestIsValidUploadKey/narinfo679=== CONT TestPendingClosureWriteTimeout680=== RUN TestPendingClosureWriteTimeout/empty681=== CONT TestProxyWriteTimeout682=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle683=== CONT TestSkippedUploadsHandler684=== CONT TestParseSize685=== CONT TestService_Rustfstest686=== CONT TestPresignedUploadRegisteredBeforeCommit687=== CONT TestCompletedNarNotReofferedAcrossClosures688=== CONT TestCompleteMultipartUpload_ErrorButObjectExists689=== CONT TestRedundantMultipartUpload690=== CONT TestPush_SignsNarinfosOfItsPendingObjects691=== CONT TestPush_RejectsBadRequests692=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit693=== CONT TestPush_CompleteCommitsEveryRoot694=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info695=== PAUSE TestIsValidUploadKey/narinfo696=== RUN TestProxyWriteTimeout/narinfo697=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal698=== RUN TestIsValidUploadKey/nar_zst699=== PAUSE TestPendingClosureWriteTimeout/empty700=== RUN TestPendingClosureWriteTimeout/400_objects701=== PAUSE TestPendingClosureWriteTimeout/400_objects702=== RUN TestPendingClosureWriteTimeout/670k_objects703=== PAUSE TestPendingClosureWriteTimeout/670k_objects704=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline7052026/10/01 10:41:29 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000706=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline707=== CONT TestPush_OverlappingRootsStoreOneRowPerKey708--- PASS: TestParseSize (0.00s)709=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal710=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key711=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key712=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key713=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key714=== PAUSE TestProxyWriteTimeout/narinfo715=== RUN TestProxyWriteTimeout/1_GiB_nar716=== PAUSE TestProxyWriteTimeout/1_GiB_nar717=== RUN TestProxyWriteTimeout/10_GiB_nar718=== PAUSE TestProxyWriteTimeout/10_GiB_nar719=== RUN TestProxyWriteTimeout/unknown_size720=== PAUSE TestProxyWriteTimeout/unknown_size721=== CONT TestReadProxyRangeRequest722=== CONT TestReadRedirectUsesPublicS3URL723=== PAUSE TestIsValidUploadKey/nar_zst724=== CONT TestReadRedirectKeepsNarinfoProxied725=== RUN TestIsValidUploadKey/nar_xz726=== PAUSE TestIsValidUploadKey/nar_xz727=== RUN TestIsValidUploadKey/nar_plain728=== PAUSE TestIsValidUploadKey/nar_plain729=== RUN TestIsValidUploadKey/listing730=== PAUSE TestIsValidUploadKey/listing731=== RUN TestIsValidUploadKey/build_log732=== PAUSE TestIsValidUploadKey/build_log733=== RUN TestIsValidUploadKey/build_log_home-manager_file734=== PAUSE TestIsValidUploadKey/build_log_home-manager_file735=== RUN TestIsValidUploadKey/build_log_plus_in_name736=== PAUSE TestIsValidUploadKey/build_log_plus_in_name737=== RUN TestIsValidUploadKey/build_log_question_mark738=== PAUSE TestIsValidUploadKey/build_log_question_mark739=== RUN TestIsValidUploadKey/build_log_equals740=== PAUSE TestIsValidUploadKey/build_log_equals741=== RUN TestIsValidUploadKey/realisation742=== PAUSE TestIsValidUploadKey/realisation743=== RUN TestIsValidUploadKey/realisation_plus_in_output744=== PAUSE TestIsValidUploadKey/realisation_plus_in_output745=== RUN TestIsValidUploadKey/nix-cache-info746=== PAUSE TestIsValidUploadKey/nix-cache-info747=== RUN TestIsValidUploadKey/index.html748=== PAUSE TestIsValidUploadKey/index.html749=== RUN TestIsValidUploadKey/narinfo_key,_nar_type750=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type751=== RUN TestIsValidUploadKey/nar_key,_narinfo_type752=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type753--- PASS: TestSkippedUploadsHandler (0.01s)754=== CONT TestReadRedirectNar755=== RUN TestIsValidUploadKey/listing_key,_narinfo_type756=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type757=== RUN TestIsValidUploadKey/traversal758=== PAUSE TestIsValidUploadKey/traversal759=== RUN TestIsValidUploadKey/traversal_nar760=== PAUSE TestIsValidUploadKey/traversal_nar761=== RUN TestIsValidUploadKey/absolute762=== PAUSE TestIsValidUploadKey/absolute763=== RUN TestIsValidUploadKey/empty_key764=== PAUSE TestIsValidUploadKey/empty_key765=== RUN TestIsValidUploadKey/unknown_type766=== PAUSE TestIsValidUploadKey/unknown_type767=== CONT TestReadProxyDisabled768=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure769=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure770=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart771=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart772=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts773=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts774=== CONT TestReadProxyRootRedirectsToIndexHTML7752026/10/01 10:41:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7762026/10/01 10:41:29 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst777--- PASS: TestCompleteMultipartUnregistered (0.43s)778=== CONT TestCommitRacingPendingCleanupKeepsObjects779--- PASS: TestReadProxyConditionalGet (0.46s)780=== CONT TestReadProxyOutlastsServerWriteTimeout7812026/10/01 10:41:29 INFO Received cleanup request method=DELETE path=/api/pending_closures7822026/10/01 10:41:29 INFO Aborted multipart uploads count=0 kept=07832026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures7842026/10/01 10:41:29 INFO Received cleanup request method=DELETE path=/api/pending_closures7852026/10/01 10:41:29 INFO Aborted multipart uploads count=1 kept=07862026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures7872026/10/01 10:41:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7882026-10-01 10:41:29.790 UTC [640] ERROR: Closure does not exist: id=17892026-10-01 10:41:29.790 UTC [640] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7902026-10-01 10:41:29.790 UTC [640] STATEMENT: -- name: CommitPendingClosure :exec791 SELECT commit_pending_closure($1::bigint)792 793--- PASS: TestService_cleanupPendingClosuresHandler (0.50s)794=== CONT TestReadProxyHead795--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.51s)796=== CONT TestReadProxyInvalidPath7972026/10/01 10:41:29 INFO Received push request method=POST path=/api/pushes7982026/10/01 10:41:29 INFO Received complete push request method=POST path=/api/pushes/1/complete7992026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures8002026/10/01 10:41:29 INFO Received push request method=POST path=/api/pushes8012026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures8022026/10/01 10:41:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8032026/10/01 10:41:29 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLmU2NjE4NzE4LWI0NDAtNDYxZS1hMjNiLTUzMDQwNTRmYWFiZHgxNzkwODUxMjg5ODQ5OTY2NjQ28042026/10/01 10:41:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLmU2NjE4NzE4LWI0NDAtNDYxZS1hMjNiLTUzMDQwNTRmYWFiZHgxNzkwODUxMjg5ODQ5OTY2NjQ2 parts=18052026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures806--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.59s)807=== CONT TestReadProxy4048082026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures8092026/10/01 10:41:29 INFO Aborted multipart uploads count=0 kept=08102026/10/01 10:41:29 WARN Force mode enabled - objects will be deleted immediately without grace period811--- PASS: TestService_Rustfstest (0.53s)812=== CONT TestReadProxyNarStreaming8132026/10/01 10:41:29 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=08142026/10/01 10:41:29 INFO Vacuumed table table=pending_closures8152026/10/01 10:41:29 INFO Vacuumed table table=pending_objects8162026/10/01 10:41:29 INFO Vacuumed table table=multipart_uploads8172026/10/01 10:41:29 INFO Vacuumed table table=closures8182026/10/01 10:41:29 INFO Vacuumed table table=objects8192026/10/01 10:41:29 INFO Received complete push request method=POST path=/api/pushes/2/complete820--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.64s)821=== CONT TestReadProxyNarinfoAlreadyDecompressed822=== RUN TestPush_RejectsBadRequests/bad_root823=== PAUSE TestPush_RejectsBadRequests/bad_root824=== RUN TestPush_RejectsBadRequests/root_not_in_objects825=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects826=== RUN TestPush_RejectsBadRequests/no_roots827=== PAUSE TestPush_RejectsBadRequests/no_roots828=== RUN TestPush_RejectsBadRequests/no_objects829=== PAUSE TestPush_RejectsBadRequests/no_objects830=== CONT TestReadProxyNarinfo8312026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures8322026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures8332026/10/01 10:41:29 INFO Received uploads request method=POST path=/api/pending_closures834--- PASS: TestReadRedirectNar (0.62s)835=== CONT TestIsValidCachePath836=== RUN TestIsValidCachePath/narinfo837=== PAUSE TestIsValidCachePath/narinfo838=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars839=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars840=== RUN TestIsValidCachePath/nar_zst841=== PAUSE TestIsValidCachePath/nar_zst842=== RUN TestIsValidCachePath/nar_xz843=== PAUSE TestIsValidCachePath/nar_xz844=== RUN TestIsValidCachePath/nar_bz2845=== PAUSE TestIsValidCachePath/nar_bz2846=== RUN TestIsValidCachePath/nar_uncompressed847=== PAUSE TestIsValidCachePath/nar_uncompressed848=== RUN TestIsValidCachePath/ls849=== PAUSE TestIsValidCachePath/ls850=== RUN TestIsValidCachePath/log851=== PAUSE TestIsValidCachePath/log852=== RUN TestIsValidCachePath/realisation853=== PAUSE TestIsValidCachePath/realisation854=== RUN TestIsValidCachePath/nix-cache-info855=== PAUSE TestIsValidCachePath/nix-cache-info856=== RUN TestIsValidCachePath/index.html857=== PAUSE TestIsValidCachePath/index.html858=== RUN TestIsValidCachePath/traversal_parent859=== PAUSE TestIsValidCachePath/traversal_parent860=== RUN TestIsValidCachePath/traversal_in_middle861=== PAUSE TestIsValidCachePath/traversal_in_middle862=== RUN TestIsValidCachePath/invalid_char_e863=== PAUSE TestIsValidCachePath/invalid_char_e864=== RUN TestIsValidCachePath/invalid_char_u865=== PAUSE TestIsValidCachePath/invalid_char_u866=== RUN TestIsValidCachePath/random_path867=== PAUSE TestIsValidCachePath/random_path868=== RUN TestIsValidCachePath/empty869=== PAUSE TestIsValidCachePath/empty870=== RUN TestIsValidCachePath/leading_slash871=== PAUSE TestIsValidCachePath/leading_slash872=== RUN TestIsValidCachePath/wrong_extension873=== PAUSE TestIsValidCachePath/wrong_extension874=== RUN TestIsValidCachePath/short_hash875=== PAUSE TestIsValidCachePath/short_hash876=== CONT TestProxyHeadersOnlyTrustedOnSocket877--- PASS: TestReadRedirectKeepsNarinfoProxied (0.65s)878=== CONT TestParseSingleRange879=== RUN TestParseSingleRange/none880=== PAUSE TestParseSingleRange/none881=== RUN TestParseSingleRange/unknown_unit882=== PAUSE TestParseSingleRange/unknown_unit883=== RUN TestParseSingleRange/multi-range_ignored884=== PAUSE TestParseSingleRange/multi-range_ignored885=== RUN TestParseSingleRange/malformed_no_dash886=== PAUSE TestParseSingleRange/malformed_no_dash887=== RUN TestParseSingleRange/malformed_both_empty888=== PAUSE TestParseSingleRange/malformed_both_empty889=== RUN TestParseSingleRange/malformed_end_before_start890=== PAUSE TestParseSingleRange/malformed_end_before_start891=== RUN TestParseSingleRange/closed892=== PAUSE TestParseSingleRange/closed893=== RUN TestParseSingleRange/open-ended894=== PAUSE TestParseSingleRange/open-ended895=== RUN TestParseSingleRange/end_clamped_to_size896=== PAUSE TestParseSingleRange/end_clamped_to_size897=== RUN TestParseSingleRange/suffix898=== PAUSE TestParseSingleRange/suffix899=== RUN TestParseSingleRange/suffix_exceeds_size900=== PAUSE TestParseSingleRange/suffix_exceeds_size901=== RUN TestParseSingleRange/single_byte902=== PAUSE TestParseSingleRange/single_byte903=== RUN TestParseSingleRange/start_past_EOF904=== PAUSE TestParseSingleRange/start_past_EOF905=== RUN TestParseSingleRange/start_far_past_EOF906=== PAUSE TestParseSingleRange/start_far_past_EOF907=== CONT TestPresentNotReportedWhileGCDeletesClosure908--- PASS: TestReadRedirectUsesPublicS3URL (0.69s)909=== CONT TestPresentReportsOnlyClosureRoots9102026/10/01 10:41:30 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"911--- PASS: TestService_AuthMiddleware (0.80s)912=== CONT TestCreatePin_ReservedPins9132026/10/01 10:41:30 INFO Received push request method=POST path=/api/pushes9142026/10/01 10:41:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37999/oidc9152026/10/01 10:41:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9162026/10/01 10:41:30 INFO Signed narinfos id=1 count=1917--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.84s)918=== CONT TestOrphanedObjectsGCStressTest9192026/10/01 10:41:30 INFO Received push request method=POST path=/api/pushes920--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.78s)921=== CONT TestOrphanedObjectsGC922--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.71s)923=== CONT TestObjectStatsTrigger924--- PASS: TestReadProxyRangeRequest (0.82s)925=== CONT TestPendingCleanupUsesOneCutoff9262026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures9272026/10/01 10:41:30 INFO Received push request method=POST path=/api/pushes9282026/10/01 10:41:30 INFO Received complete push request method=POST path=/api/pushes/1/complete929--- PASS: TestPush_CompleteCommitsEveryRoot (0.92s)930=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded931--- PASS: TestReadProxyDisabled (0.93s)932=== CONT TestMultipartCleanup9332026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures9342026/10/01 10:41:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9352026/10/01 10:41:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9362026/10/01 10:41:30 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9372026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures938--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.00s)939=== CONT TestServerTLSConfig940=== RUN TestServerTLSConfig/no_client_CA941=== PAUSE TestServerTLSConfig/no_client_CA942=== RUN TestServerTLSConfig/missing_CA_file943=== PAUSE TestServerTLSConfig/missing_CA_file944=== RUN TestServerTLSConfig/not_a_PEM_file945=== PAUSE TestServerTLSConfig/not_a_PEM_file946=== CONT TestService_NativeMTLS9472026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures9482026/10/01 10:41:30 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLmI4Y2MwZmFhLWRiZDUtNGEyOC1iYTE2LTYwMzhhMjhhMzRmOXgxNzkwODUxMjg5ODc4Mjk5Nzcy parts=109492026/10/01 10:41:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9502026/10/01 10:41:30 INFO Completed upload id=19512026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures9522026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/01 10:41:30 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9542026/10/01 10:41:30 WARN Found objects in DB but missing from S3, will re-upload count=1955--- PASS: TestService_verifyS3Integrity (1.11s)956=== CONT TestMetricsInventory9572026/10/01 10:41:30 INFO Aborted multipart uploads count=0 kept=09582026/10/01 10:41:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9592026/10/01 10:41:30 WARN Force mode enabled - objects will be deleted immediately without grace period9602026/10/01 10:41:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9612026/10/01 10:41:30 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=09622026/10/01 10:41:30 INFO Vacuumed table table=pending_closures9632026/10/01 10:41:30 INFO Vacuumed table table=pending_objects9642026/10/01 10:41:30 INFO Vacuumed table table=multipart_uploads9652026/10/01 10:41:30 INFO Vacuumed table table=closures9662026/10/01 10:41:30 INFO Vacuumed table table=objects967--- PASS: TestReadProxyHead (0.68s)968=== CONT TestConnectWaitsForAPeerMigration969--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.76s)970=== CONT TestNARDeduplicationMetadataUploadBug9712026/10/01 10:41:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLjAwODBhOWM5LTUxODQtNDc4Ni1iOTJiLTk3MWYzOGJmNjQxMHgxNzkwODUxMjg5OTAxOTUzMzE4 parts=129722026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures9732026/10/01 10:41:30 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLjZiNTUyYjY1LTJhNmMtNDNjNS05NzE5LWU0M2QwY2I5MGVmMXgxNzkwODUxMjg5OTk0Njk3NTc4 parts=109742026/10/01 10:41:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9752026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures9762026/10/01 10:41:30 INFO Completed upload id=19772026/10/01 10:41:30 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009782026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures979--- PASS: TestReadProxyInvalidPath (0.69s)980=== CONT TestCreatePendingClosureRejectsOversizedNAR9812026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures982--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)983=== CONT TestPushWaitsForSweepHoldingRow9842026/10/01 10:41:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures9852026/10/01 10:41:30 INFO Aborted multipart uploads count=0 kept=09862026/10/01 10:41:30 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=09872026/10/01 10:41:30 INFO Vacuumed table table=pending_closures9882026/10/01 10:41:30 INFO Vacuumed table table=pending_objects9892026/10/01 10:41:30 INFO Vacuumed table table=multipart_uploads9902026/10/01 10:41:30 INFO Vacuumed table table=closures9912026/10/01 10:41:30 INFO Vacuumed table table=objects992--- PASS: TestReadProxy404 (0.66s)993=== CONT TestCacheConfigHandlerMaxNarSize994--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)995=== CONT TestGenerateLandingPage996--- PASS: TestGenerateLandingPage (0.00s)9972026/10/01 10:41:30 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000998=== CONT TestSweepRechecksPendingAfterLocking999--- PASS: TestService_createPendingClosureHandler (1.26s)1000=== CONT TestService_readinessHandler1001--- PASS: TestReadProxyNarStreaming (0.65s)1002=== CONT TestGetExistingObjectsLocksRows1003--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.65s)1004=== CONT TestService_healthCheckHandler10052026/10/01 10:41:30 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1588698085/001/proxy.sock10062026/10/01 10:41:30 INFO Starting HTTP server address=127.0.0.1:3334710072026/10/01 10:41:30 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10082026/10/01 10:41:30 INFO Shutdown signal received, draining in-flight requests timeout=10s1009--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.64s)1010=== CONT TestGracefulShutdownDrainsInflight10112026/10/01 10:41:30 INFO Starting HTTP server address=127.0.0.1:4553910122026/10/01 10:41:30 INFO Shutdown signal received, draining in-flight requests timeout=10s10132026/10/01 10:41:30 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1014--- PASS: TestPresentReportsOnlyClosureRoots (0.64s)1015=== CONT TestRegisterCompletedObjectNeedsPendingRow1016--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1017=== CONT TestGCTaskStore_Fail1018--- PASS: TestGCTaskStore_Fail (0.00s)1019=== CONT TestSweepSkipsRowsLockedByPush10202026/10/01 10:41:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10212026/10/01 10:41:30 WARN Refused reserved pin name=worker-x86_64-linux10222026/10/01 10:41:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10232026/10/01 10:41:30 INFO Received create pin request method=POST path=/api/pins/my-app10242026/10/01 10:41:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1025--- PASS: TestCreatePin_ReservedPins (0.64s)1026=== CONT TestGCTaskStore_PhaseUpdates1027--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1028=== CONT TestFailedS3DeleteKeepsTombstone1029--- PASS: TestObjectStatsTrigger (0.64s)1030=== CONT TestGCTaskStore_CompletedAllowsNewTask1031--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1032=== CONT TestForceGCDuringPushOffersSweptObject1033=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1034=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1035=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1036=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1037=== CONT TestGCTaskStore_GetReturnsLatest1038--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1039=== CONT TestGCTaskStore_GetEmpty1040--- PASS: TestGCTaskStore_GetEmpty (0.00s)1041=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10422026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures10432026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures10442026/10/01 10:41:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10452026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures1046--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.56s)10472026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures1048=== CONT TestGCTaskStore_ConflictDifferentParams1049--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1050=== CONT TestGCSweepDeliversEachKeyOnce10512026/10/01 10:41:30 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161052--- PASS: TestReadProxyNarinfo (0.93s)1053=== CONT TestGCTaskStore_DeduplicateSameParams1054--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1055=== CONT TestTombstonedObjectOfferedWithoutWaiting10562026/10/01 10:41:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10572026/10/01 10:41:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1058--- PASS: TestService_NativeMTLS (0.51s)1059=== CONT TestGCTaskStore_StartNew1060--- PASS: TestGCTaskStore_StartNew (0.00s)1061=== CONT TestGCSweepSkipsPendingObjects10622026/10/01 10:41:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1063--- PASS: TestMetricsInventory (0.53s)1064=== CONT TestGCEndsOnShutdown10652026/10/01 10:41:30 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLjJlMGE0NTBlLWMyNzUtNDMxNi05NTk2LWY4ZDM1MTk4MDhmYXgxNzkwODUxMjkwMzkzMjMzNTQ3 parts=1210662026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures1067--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.57s)1068=== CONT TestDeduplicatedObjectsRecordedAsPending10692026/10/01 10:41:30 INFO Received uploads request method=POST path=/api/pending_closures1070=== NAME TestNARDeduplicationMetadataUploadBug1071 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1263372000/001/store/hxzv7cgmj61zwpr7i3kphfkfvlmg3w4g-file1.txt10722026/10/01 10:41:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10732026/10/01 10:41:30 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket43/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10742026/10/01 10:41:30 INFO Aborted multipart uploads count=0 kept=110752026/10/01 10:41:30 INFO Received cleanup request method=DELETE path=/api/pending_closures10762026/10/01 10:41:30 INFO Aborted multipart uploads count=1 kept=010772026/10/01 10:41:31 WARN readiness check failed error="closed pool"1078--- PASS: TestService_readinessHandler (0.45s)1079=== CONT TestPushDedupSurvivesConcurrentGC1080--- PASS: TestMultipartCleanup (0.69s)1081=== CONT TestClientErrorHandling1082=== RUN TestClientErrorHandling/InvalidStorePath1083=== PAUSE TestClientErrorHandling/InvalidStorePath1084=== RUN TestClientErrorHandling/InvalidAuthToken1085=== PAUSE TestClientErrorHandling/InvalidAuthToken1086=== RUN TestClientErrorHandling/ServerNotAvailable1087=== PAUSE TestClientErrorHandling/ServerNotAvailable1088=== CONT TestGCMetrics10892026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=010902026/10/01 10:41:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10912026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/10/01 10:41:31 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLmUxOWZmZGZkLTBlNDYtNDIyMS1hNzAzLTVhMTc3NzcxMWQ1NngxNzkwODUxMjkwNDkwNDk1Mjg3 error="Get \"http://127.0.0.1:1/bucket9/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10932026/10/01 10:41:31 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTMyODE5YzEtYjA1MS00ZjVjLWIwZjMtOTkwOWFjNTk3ZDQxLjU2ZjRhNjU5LWVjNDQtNDMyNi05MmY1LWI4YmY0MTgyNWY3Y3gxNzkwODUxMjkwNDg0MDI1NTEx parts=1210942026/10/01 10:41:31 INFO Received cleanup request method=DELETE path=/api/pending_closures10952026/10/01 10:41:31 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=010962026/10/01 10:41:31 INFO Aborted multipart uploads count=1 kept=010972026/10/01 10:41:31 INFO Vacuumed table table=pending_closures10982026/10/01 10:41:31 INFO Vacuumed table table=pending_objects10992026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads1100--- PASS: TestRedundantMultipartUpload (1.74s)11012026/10/01 10:41:31 INFO Vacuumed table table=closures1102=== CONT TestResolveDBConnectionString1103=== RUN TestResolveDBConnectionString/flag_wins1104=== PAUSE TestResolveDBConnectionString/flag_wins1105=== RUN TestResolveDBConnectionString/file_when_flag_empty1106=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1107=== RUN TestResolveDBConnectionString/missing_file_is_an_error1108=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1109=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1110=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1111=== RUN TestResolveDBConnectionString/nothing_configured1112=== PAUSE TestResolveDBConnectionString/nothing_configured1113=== CONT TestGCBugBareHashReferences1114--- PASS: TestGetExistingObjectsLocksRows (0.48s)11152026/10/01 10:41:31 INFO Vacuumed table table=objects1116=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1117--- PASS: TestSweepRechecksPendingAfterLocking (0.49s)1118=== CONT TestGCAdvisoryLockBlocksConcurrentRun1119--- PASS: TestService_healthCheckHandler (0.46s)1120=== CONT TestClientFallsBackToClosures11212026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes11222026/10/01 10:41:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11232026/10/01 10:41:31 INFO Uploading hxzv7cgmj61zwpr7i3kphfkfvlmg3w4g-file1.txt (160B)11242026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11252026/10/01 10:41:31 WARN Failed to register uploaded object key=hxzv7cgmj61zwpr7i3kphfkfvlmg3w4g.ls error="server returned 404: 404 page not found\n"11262026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11272026/10/01 10:41:31 INFO Signed narinfos id=1 count=111282026/10/01 10:41:31 INFO Uploading 1 narinfos1129--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.37s)1130=== CONT TestClientPushesUseOnePush11312026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/1/complete11322026/10/01 10:41:31 WARN Failed to register uploaded object key=hxzv7cgmj61zwpr7i3kphfkfvlmg3w4g.narinfo error="server returned 404: 404 page not found\n"11332026/10/01 10:41:31 INFO Upload complete. (63ms)1134=== NAME TestNARDeduplicationMetadataUploadBug1135 metadata_upload_test.go:54: Retrieved narinfo from S3:1136 StorePath: /build/TestNARDeduplicationMetadataUploadBug1263372000/001/store/hxzv7cgmj61zwpr7i3kphfkfvlmg3w4g-file1.txt1137 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1138 Compression: zstd1139 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1140 NarSize: 1601141 References: 1142 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1143 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1144 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1145 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1146=== NAME TestOrphanedObjectsGC1147 orphaned_objects_gc_test.go:290: GC Test Summary:1148 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1149 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1150 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1151 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1152 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1153--- PASS: TestOrphanedObjectsGC (0.93s)1154=== CONT TestLeadEndsOnShutdown11552026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=011562026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period11582026/10/01 10:41:31 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=011592026/10/01 10:41:31 INFO Vacuumed table table=pending_closures1160=== NAME TestNARDeduplicationMetadataUploadBug1161 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1263372000/001/store/y6hhs723j1fwghmzcy42xxb8dqi2yrs1-file2.txt11622026/10/01 10:41:31 INFO Vacuumed table table=pending_objects11632026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads11642026/10/01 10:41:31 INFO Vacuumed table table=closures11652026/10/01 10:41:31 INFO Vacuumed table table=objects11662026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures11672026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=011682026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period11692026/10/01 10:41:31 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=011702026/10/01 10:41:31 INFO Vacuumed table table=pending_closures11712026/10/01 10:41:31 INFO Vacuumed table table=pending_objects11722026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads11732026/10/01 10:41:31 INFO Vacuumed table table=closures11742026/10/01 10:41:31 INFO Vacuumed table table=objects1175--- PASS: TestSweepSkipsRowsLockedByPush (0.46s)1176=== CONT TestPinProtectsFromGC11772026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures1178--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.15s)1179=== CONT TestLeadElectsOneAndHandsOver1180--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.31s)1181=== CONT TestClientSharedPathCommittedMidPush11822026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes11832026/10/01 10:41:31 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11842026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11852026/10/01 10:41:31 WARN Failed to register uploaded object key=y6hhs723j1fwghmzcy42xxb8dqi2yrs1.ls error="server returned 404: 404 page not found\n"11862026/10/01 10:41:31 INFO Signed narinfos id=2 count=111872026/10/01 10:41:31 INFO Uploading 1 narinfos11882026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=011892026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/2/complete11902026/10/01 10:41:31 WARN Failed to register uploaded object key=y6hhs723j1fwghmzcy42xxb8dqi2yrs1.narinfo error="server returned 404: 404 page not found\n"11912026/10/01 10:41:31 INFO Upload complete. (67ms)1192=== NAME TestNARDeduplicationMetadataUploadBug1193 metadata_upload_test.go:76: Retrieved narinfo from S3:11942026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period1195 StorePath: /build/TestNARDeduplicationMetadataUploadBug1263372000/001/store/y6hhs723j1fwghmzcy42xxb8dqi2yrs1-file2.txt1196 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1197 Compression: zstd1198 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1199 NarSize: 1601200 References: 1201 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1202 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1203 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1204 {"version":1,"root":{"type":"regular","size":44}}12052026/10/01 10:41:31 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12062026/10/01 10:41:31 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1207--- PASS: TestNARDeduplicationMetadataUploadBug (0.77s)1208=== CONT TestClientWithDependencies12092026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=012102026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period12112026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures1212--- PASS: TestFailedS3DeleteKeepsTombstone (0.53s)1213=== CONT TestClientMultipleUploads12142026/10/01 10:41:31 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=012152026/10/01 10:41:31 INFO Vacuumed table table=pending_closures12162026/10/01 10:41:31 INFO Vacuumed table table=pending_objects12172026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads12182026/10/01 10:41:31 INFO Vacuumed table table=closures1219--- PASS: TestGCEndsOnShutdown (0.34s)1220=== CONT TestClientIntegration12212026/10/01 10:41:31 INFO Vacuumed table table=objects1222--- PASS: TestGCSweepDeliversEachKeyOnce (0.41s)1223=== CONT TestService_RequireScope_OIDC12242026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=012252026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period12262026/10/01 10:41:31 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=012272026/10/01 10:41:31 INFO Vacuumed table table=pending_closures12282026/10/01 10:41:31 INFO Vacuumed table table=pending_objects12292026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads12302026/10/01 10:41:31 INFO Vacuumed table table=closures12312026/10/01 10:41:31 INFO Vacuumed table table=objects12322026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures1233--- PASS: TestGCSweepSkipsPendingObjects (0.42s)1234=== CONT TestService_ReadAuthMiddleware1235--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.36s)1236=== CONT TestClientCADerivations12372026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=012382026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period12392026/10/01 10:41:31 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=012402026/10/01 10:41:31 INFO Vacuumed table table=pending_closures12412026/10/01 10:41:31 INFO Vacuumed table table=pending_objects12422026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads12432026/10/01 10:41:31 INFO Vacuumed table table=closures12442026/10/01 10:41:31 INFO Vacuumed table table=objects1245--- PASS: TestGCMetrics (0.35s)1246=== CONT TestService_AuthMiddleware_OIDC1247--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.55s)1248=== CONT TestCacheStatsHandler12492026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/01 10:41:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43195/oidc12512026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=012522026/10/01 10:41:31 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=012532026/10/01 10:41:31 INFO Vacuumed table table=pending_closures12542026/10/01 10:41:31 INFO Vacuumed table table=pending_objects12552026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads12562026/10/01 10:41:31 INFO Vacuumed table table=closures12572026/10/01 10:41:31 INFO Vacuumed table table=objects1258--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.42s)1259=== CONT TestCacheConfigHandler1260=== RUN TestCacheConfigHandler/full_config,_no_issuer1261=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1262=== RUN TestCacheConfigHandler/no_cache_url_configured1263=== PAUSE TestCacheConfigHandler/no_cache_url_configured1264=== RUN TestCacheConfigHandler/no_signing_keys1265=== PAUSE TestCacheConfigHandler/no_signing_keys1266=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1267=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1268=== CONT TestService_ReadScope_PublicByDefault1269--- PASS: TestPushWaitsForSweepHoldingRow (0.97s)1270=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12712026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=012722026/10/01 10:41:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35379/oidc12732026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period12742026/10/01 10:41:31 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=012752026/10/01 10:41:31 INFO Vacuumed table table=pending_closures12762026/10/01 10:41:31 INFO Vacuumed table table=pending_objects12772026/10/01 10:41:31 INFO Vacuumed table table=multipart_uploads12782026/10/01 10:41:31 INFO Vacuumed table table=closures12792026/10/01 10:41:31 INFO Vacuumed table table=objects1280--- PASS: TestPushDedupSurvivesConcurrentGC (0.48s)1281=== CONT TestService_AuthMiddleware_MTLSProxyHeader12822026/10/01 10:41:31 INFO lead: acquired remote=192.0.2.1:123412832026/10/01 10:41:31 INFO lead: released remote=192.0.2.1:12341284--- PASS: TestLeadEndsOnShutdown (0.42s)1285=== CONT TestPendingClosureWriteTimeout/empty1286=== CONT TestPendingClosureWriteTimeout/670k_objects1287=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline12882026/10/01 10:41:31 INFO lead: acquired remote=192.0.2.1:12341289--- PASS: TestGCBugBareHashReferences (0.56s)1290=== CONT TestPendingClosureWriteTimeout/400_objects1291=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info12922026/10/01 10:41:31 INFO Received uploads request method=POST path=/1293=== CONT TestProxyWriteTimeout/narinfo1294=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key12952026/10/01 10:41:31 INFO Received complete multipart upload request method=POST path=/1296=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key12972026/10/01 10:41:31 INFO Received request for more parts method=POST path=/1298=== CONT TestProxyWriteTimeout/unknown_size1299=== CONT TestProxyWriteTimeout/10_GiB_nar1300=== CONT TestProxyWriteTimeout/1_GiB_nar1301--- PASS: TestProxyWriteTimeout (0.09s)1302 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1303 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1304 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1305 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1306=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13072026/10/01 10:41:31 INFO Received uploads request method=POST path=/1308--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)1309 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1310 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1311 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1312 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1313=== CONT TestIsValidUploadKey/narinfo1314=== CONT TestIsValidUploadKey/empty_key1315=== CONT TestIsValidUploadKey/absolute1316=== CONT TestIsValidUploadKey/traversal_nar1317=== CONT TestIsValidUploadKey/traversal1318=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1319=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1320=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1321=== CONT TestIsValidUploadKey/index.html1322=== CONT TestIsValidUploadKey/nix-cache-info1323=== CONT TestIsValidUploadKey/realisation_plus_in_output1324=== CONT TestIsValidUploadKey/realisation1325=== CONT TestIsValidUploadKey/build_log_equals1326=== CONT TestIsValidUploadKey/build_log_question_mark1327=== CONT TestIsValidUploadKey/build_log_plus_in_name1328=== CONT TestIsValidUploadKey/build_log_home-manager_file1329=== CONT TestIsValidUploadKey/build_log1330=== CONT TestIsValidUploadKey/listing1331=== CONT TestIsValidUploadKey/nar_plain1332=== CONT TestIsValidUploadKey/nar_xz1333=== CONT TestIsValidUploadKey/unknown_type1334=== CONT TestIsValidUploadKey/nar_zst1335--- PASS: TestIsValidUploadKey (0.09s)1336 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1337 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1338 --- PASS: TestIsValidUploadKey/absolute (0.00s)1339 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1340 --- PASS: TestIsValidUploadKey/traversal (0.00s)1341 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1342 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1343 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1344 --- PASS: TestIsValidUploadKey/index.html (0.00s)1345 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1346 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1347 --- PASS: TestIsValidUploadKey/realisation (0.00s)1348 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1349 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1350 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1351 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1352 --- PASS: TestIsValidUploadKey/build_log (0.00s)1353 --- PASS: TestIsValidUploadKey/listing (0.00s)1354 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1355 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1356 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1357 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1358=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13592026/10/01 10:41:31 INFO Received uploads request method=POST path=/13602026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures13612026/10/01 10:41:31 INFO Received uploads request method=POST path=/api/pending_closures13622026/10/01 10:41:31 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13632026/10/01 10:41:31 INFO Uploading cmfyy98q9mpn5gmbxn8gl91wbgi8hjpg-shared-dep (136B)13642026/10/01 10:41:31 INFO Uploading wfllm1y48vxizj934mnvq4hs5da392df-a (216B)1365=== NAME TestPinProtectsFromGC1366 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3365888316/001/store/zqq8m9i7rm3zb5gp29lzm07qywjjawfp-pinned-file.txt1367 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3365888316/001/store/lvcxnvg942lp91ily5k8q5xx4ic5r24i-unpinned-file.txt13682026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13692026/10/01 10:41:31 WARN Failed to register uploaded object key=24v7xhn3p08ish35vs8vicfr4ykkgkwm.ls error="server returned 404: 404 page not found\n"13702026/10/01 10:41:31 WARN Failed to register uploaded object key=cmfyy98q9mpn5gmbxn8gl91wbgi8hjpg.ls error="server returned 404: 404 page not found\n"13712026/10/01 10:41:31 WARN Failed to register uploaded object key=wfllm1y48vxizj934mnvq4hs5da392df.ls error="server returned 404: 404 page not found\n"13722026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13732026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/1qwyyxl9wvqmvml91w67173zjfkr5msrml9p54az2647bisj4qas.nar.zst error="server returned 404: 404 page not found\n"13742026/10/01 10:41:31 INFO Signed narinfos id=1 count=213752026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13762026/10/01 10:41:31 INFO Signed narinfos id=2 count=213772026/10/01 10:41:31 INFO Uploading 4 narinfos13782026/10/01 10:41:31 WARN Failed to register uploaded object key=cmfyy98q9mpn5gmbxn8gl91wbgi8hjpg.narinfo error="server returned 404: 404 page not found\n"13792026/10/01 10:41:31 WARN Failed to register uploaded object key=24v7xhn3p08ish35vs8vicfr4ykkgkwm.narinfo error="server returned 404: 404 page not found\n"13802026/10/01 10:41:31 WARN Failed to register uploaded object key=cmfyy98q9mpn5gmbxn8gl91wbgi8hjpg.narinfo error="server returned 404: 404 page not found\n"13812026/10/01 10:41:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13822026/10/01 10:41:31 WARN Failed to register uploaded object key=wfllm1y48vxizj934mnvq4hs5da392df.narinfo error="server returned 404: 404 page not found\n"13832026/10/01 10:41:31 INFO Completed upload id=113842026/10/01 10:41:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13852026/10/01 10:41:31 INFO Completed upload id=213862026/10/01 10:41:31 INFO Upload complete. (75ms)1387=== NAME TestClientFallsBackToClosures1388 client_pushes_test.go:112: Retrieved narinfo from S3:1389 StorePath: /build/TestClientFallsBackToClosures1789924953/001/store/cmfyy98q9mpn5gmbxn8gl91wbgi8hjpg-shared-dep1390 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1391 Compression: zstd1392 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821393 NarSize: 1361394 References: 1395 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1396 client_pushes_test.go:112: Retrieved narinfo from S3:1397 StorePath: /build/TestClientFallsBackToClosures1789924953/001/store/wfllm1y48vxizj934mnvq4hs5da392df-a1398 URL: nar/1qwyyxl9wvqmvml91w67173zjfkr5msrml9p54az2647bisj4qas.nar.zst1399 Compression: zstd1400 NarHash: sha256:1qwyyxl9wvqmvml91w67173zjfkr5msrml9p54az2647bisj4qas1401 NarSize: 2161402 References: /build/TestClientFallsBackToClosures1789924953/001/store/cmfyy98q9mpn5gmbxn8gl91wbgi8hjpg-shared-dep1403 CA: text:sha256:1svi361v5rsgq6byg1b24y2mb5xpp6x1krpyik87rwq2y171mpb31404 client_pushes_test.go:112: Retrieved narinfo from S3:1405 StorePath: /build/TestClientFallsBackToClosures1789924953/001/store/24v7xhn3p08ish35vs8vicfr4ykkgkwm-b1406 URL: nar/1qwyyxl9wvqmvml91w67173zjfkr5msrml9p54az2647bisj4qas.nar.zst1407 Compression: zstd1408 NarHash: sha256:1qwyyxl9wvqmvml91w67173zjfkr5msrml9p54az2647bisj4qas1409 NarSize: 2161410 References: /build/TestClientFallsBackToClosures1789924953/001/store/cmfyy98q9mpn5gmbxn8gl91wbgi8hjpg-shared-dep1411 CA: text:sha256:1svi361v5rsgq6byg1b24y2mb5xpp6x1krpyik87rwq2y171mpb31412--- PASS: TestClientFallsBackToClosures (0.63s)1413=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14142026/10/01 10:41:31 INFO Received request for more parts method=POST path=/14152026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1416=== NAME TestClientMultipleUploads1417 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1369529074/001/store/a63b1alfki95vkdyhj49yda8f13zhijj-test-file-0.txt14182026/10/01 10:41:31 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14192026/10/01 10:41:31 INFO Uploading jh5s2c454inh2zp029br18v3dyl3ba5c-shared-dep (136B)14202026/10/01 10:41:31 INFO Uploading gwhvghkdlpmc8i0f7pisbxmsab6ciyw5-b (208B)14212026/10/01 10:41:31 WARN Failed to register uploaded object key=ank4np9vb5chr29mm5bjv2p0sl1a9g2s.ls error="server returned 404: 404 page not found\n"14222026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14232026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/0fr7pcxli5ql4f97iskjh360i6vvy3r7915sfn6gnsvhqsib0c9l.nar.zst error="server returned 404: 404 page not found\n"14242026/10/01 10:41:31 WARN Failed to register uploaded object key=gwhvghkdlpmc8i0f7pisbxmsab6ciyw5.ls error="server returned 404: 404 page not found\n"14252026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14262026/10/01 10:41:31 WARN Failed to register uploaded object key=jh5s2c454inh2zp029br18v3dyl3ba5c.ls error="server returned 404: 404 page not found\n"14272026/10/01 10:41:31 INFO Signed narinfos id=1 count=314282026/10/01 10:41:31 INFO Uploading 3 narinfos14292026/10/01 10:41:31 WARN Failed to register uploaded object key=ank4np9vb5chr29mm5bjv2p0sl1a9g2s.narinfo error="server returned 404: 404 page not found\n"14302026/10/01 10:41:31 WARN Failed to register uploaded object key=jh5s2c454inh2zp029br18v3dyl3ba5c.narinfo error="server returned 404: 404 page not found\n"14312026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/1/complete14322026/10/01 10:41:31 WARN Failed to register uploaded object key=gwhvghkdlpmc8i0f7pisbxmsab6ciyw5.narinfo error="server returned 404: 404 page not found\n"1433=== NAME TestClientWithDependencies1434 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies4141536189/001/store/3vqzlzqj76irlvwzm0zdxwl9j9c88kl7-test-script14352026/10/01 10:41:31 INFO Upload complete. (66ms)14362026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1437=== NAME TestClientPushesUseOnePush1438 client_pushes_test.go:97: Retrieved narinfo from S3:1439 StorePath: /build/TestClientPushesUseOnePush841828402/001/store/jh5s2c454inh2zp029br18v3dyl3ba5c-shared-dep1440 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1441 Compression: zstd1442 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821443 NarSize: 1361444 References: 1445 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1446--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.68s)1447=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14482026/10/01 10:41:31 INFO Received complete multipart upload request method=POST path=/14492026/10/01 10:41:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14502026/10/01 10:41:31 INFO Uploading zqq8m9i7rm3zb5gp29lzm07qywjjawfp-pinned-file.txt (128B)1451=== NAME TestClientPushesUseOnePush1452 client_pushes_test.go:97: Retrieved narinfo from S3:1453 StorePath: /build/TestClientPushesUseOnePush841828402/001/store/ank4np9vb5chr29mm5bjv2p0sl1a9g2s-a1454 URL: nar/0fr7pcxli5ql4f97iskjh360i6vvy3r7915sfn6gnsvhqsib0c9l.nar.zst1455 Compression: zstd1456 NarHash: sha256:0fr7pcxli5ql4f97iskjh360i6vvy3r7915sfn6gnsvhqsib0c9l1457 NarSize: 2081458 References: /build/TestClientPushesUseOnePush841828402/001/store/jh5s2c454inh2zp029br18v3dyl3ba5c-shared-dep1459 CA: text:sha256:17yjvjn2ddpihz5db7pj7ci18jxqn59jx9xd5wgmh87nyrr4lj7z1460=== NAME TestClientIntegration1461 client_integration_test.go:286: Created store path: /build/TestClientIntegration1286235400/002/store/faaz2i1p0b1c46ij9shcpvxivc8p94s8-test-file.txt1462=== NAME TestClientPushesUseOnePush1463 client_pushes_test.go:97: Retrieved narinfo from S3:1464 StorePath: /build/TestClientPushesUseOnePush841828402/001/store/gwhvghkdlpmc8i0f7pisbxmsab6ciyw5-b1465 URL: nar/0fr7pcxli5ql4f97iskjh360i6vvy3r7915sfn6gnsvhqsib0c9l.nar.zst1466 Compression: zstd1467 NarHash: sha256:0fr7pcxli5ql4f97iskjh360i6vvy3r7915sfn6gnsvhqsib0c9l1468 NarSize: 2081469 References: /build/TestClientPushesUseOnePush841828402/001/store/jh5s2c454inh2zp029br18v3dyl3ba5c-shared-dep1470 CA: text:sha256:17yjvjn2ddpihz5db7pj7ci18jxqn59jx9xd5wgmh87nyrr4lj7z14712026/10/01 10:41:31 WARN Failed to register uploaded object key=zqq8m9i7rm3zb5gp29lzm07qywjjawfp.ls error="server returned 404: 404 page not found\n"14722026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14732026/10/01 10:41:31 INFO Signed narinfos id=1 count=114742026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14752026/10/01 10:41:31 INFO Uploading 1 narinfos1476--- PASS: TestService_ReadAuthMiddleware (0.42s)1477=== CONT TestPush_RejectsBadRequests/bad_root14782026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1479=== CONT TestPush_RejectsBadRequests/no_roots14802026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes14812026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1482=== CONT TestPush_RejectsBadRequests/no_objects14832026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1484=== CONT TestPush_RejectsBadRequests/root_not_in_objects14852026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1486=== CONT TestIsValidCachePath/narinfo1487=== NAME TestClientMultipleUploads1488 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1369529074/001/store/k821n77q754k088hsnbim6civd3d5cx2-test-file-1.txt1489--- PASS: TestPush_RejectsBadRequests (0.64s)1490 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1491 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1492 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1493 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1494=== CONT TestIsValidCachePath/index.html1495=== CONT TestIsValidCachePath/short_hash1496=== CONT TestIsValidCachePath/wrong_extension1497=== CONT TestIsValidCachePath/leading_slash1498=== CONT TestIsValidCachePath/empty1499=== CONT TestIsValidCachePath/random_path1500=== CONT TestIsValidCachePath/invalid_char_u1501=== CONT TestIsValidCachePath/invalid_char_e1502=== CONT TestIsValidCachePath/traversal_in_middle1503=== CONT TestIsValidCachePath/traversal_parent1504=== CONT TestIsValidCachePath/nar_xz1505=== CONT TestIsValidCachePath/nar_uncompressed1506=== CONT TestIsValidCachePath/nar_bz21507=== CONT TestIsValidCachePath/nix-cache-info1508=== CONT TestIsValidCachePath/realisation1509=== CONT TestIsValidCachePath/nar_zst1510=== CONT TestIsValidCachePath/log1511=== CONT TestIsValidCachePath/ls1512=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1513--- PASS: TestIsValidCachePath (0.00s)1514 --- PASS: TestIsValidCachePath/narinfo (0.00s)1515 --- PASS: TestIsValidCachePath/index.html (0.00s)1516 --- PASS: TestIsValidCachePath/short_hash (0.00s)1517 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1518 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1519 --- PASS: TestIsValidCachePath/empty (0.00s)1520 --- PASS: TestIsValidCachePath/random_path (0.00s)1521 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1522 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1523 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1524 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1525 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1526 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1527 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1528 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1529 --- PASS: TestIsValidCachePath/realisation (0.00s)1530 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1531 --- PASS: TestIsValidCachePath/log (0.00s)1532 --- PASS: TestIsValidCachePath/ls (0.00s)1533 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1534=== CONT TestParseSingleRange/none1535=== CONT TestParseSingleRange/open-ended1536=== CONT TestParseSingleRange/start_far_past_EOF1537=== CONT TestParseSingleRange/malformed_both_empty1538=== CONT TestParseSingleRange/start_past_EOF1539=== CONT TestParseSingleRange/closed1540=== CONT TestParseSingleRange/malformed_end_before_start1541=== CONT TestParseSingleRange/single_byte1542=== CONT TestParseSingleRange/suffix_exceeds_size1543=== CONT TestParseSingleRange/suffix1544=== CONT TestParseSingleRange/multi-range_ignored1545=== CONT TestParseSingleRange/malformed_no_dash1546=== CONT TestParseSingleRange/end_clamped_to_size1547=== CONT TestParseSingleRange/unknown_unit1548--- PASS: TestParseSingleRange (0.00s)1549 --- PASS: TestParseSingleRange/none (0.00s)1550 --- PASS: TestParseSingleRange/open-ended (0.00s)1551 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1552 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1553 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1554 --- PASS: TestParseSingleRange/closed (0.00s)1555 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1556 --- PASS: TestParseSingleRange/single_byte (0.00s)1557 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1558 --- PASS: TestParseSingleRange/suffix (0.00s)1559 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1560 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1561 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1562 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1563=== CONT TestServerTLSConfig/no_client_CA1564=== CONT TestServerTLSConfig/missing_CA_file1565--- PASS: TestClientPushesUseOnePush (0.65s)1566=== CONT TestServerTLSConfig/not_a_PEM_file1567=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1568--- PASS: TestServerTLSConfig (0.00s)1569 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1570 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1571 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)15722026/10/01 10:41:31 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)1573=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15742026/10/01 10:41:31 INFO Uploading 2ivkpxkqcyhicv6dsfd2bm781qix08md-shared-dep (136B)15752026/10/01 10:41:31 INFO Uploading 1wvw35bvyjbskilhmcxbsbwmbn3nss2m-top (224B)15762026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/1/complete15772026/10/01 10:41:31 WARN Failed to register uploaded object key=zqq8m9i7rm3zb5gp29lzm07qywjjawfp.narinfo error="server returned 404: 404 page not found\n"15782026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15792026/10/01 10:41:31 INFO Upload complete. (62ms)15802026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/0da2j0iz2v8n3lzkhnlww3kh7fxy6s7c8isx5hc9gsdv1fgmm2v0.nar.zst error="server returned 404: 404 page not found\n"15812026/10/01 10:41:31 WARN Failed to register uploaded object key=2ivkpxkqcyhicv6dsfd2bm781qix08md.ls error="server returned 404: 404 page not found\n"15822026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15832026/10/01 10:41:31 WARN Failed to register uploaded object key=1wvw35bvyjbskilhmcxbsbwmbn3nss2m.ls error="server returned 404: 404 page not found\n"15842026/10/01 10:41:31 INFO Signed narinfos id=1 count=215852026/10/01 10:41:31 INFO Uploading 2 narinfos15862026/10/01 10:41:31 INFO lead: released remote=192.0.2.1:12341587=== NAME TestClientWithDependencies1588 client_integration_test.go:615: Found 1 dependencies (including self)15892026/10/01 10:41:31 WARN Failed to register uploaded object key=1wvw35bvyjbskilhmcxbsbwmbn3nss2m.narinfo error="server returned 404: 404 page not found\n"1590=== CONT TestClientErrorHandling/InvalidStorePath15912026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/1/complete15922026/10/01 10:41:31 WARN Failed to register uploaded object key=2ivkpxkqcyhicv6dsfd2bm781qix08md.narinfo error="server returned 404: 404 page not found\n"15932026/10/01 10:41:31 INFO Upload complete. (66ms)1594=== NAME TestClientSharedPathCommittedMidPush1595 client_integration_test.go:680: Retrieved narinfo from S3:1596 StorePath: /build/TestClientSharedPathCommittedMidPush660049111/001/store/2ivkpxkqcyhicv6dsfd2bm781qix08md-shared-dep1597 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1598 Compression: zstd1599 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821600 NarSize: 1361601 References: 1602 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1603 client_integration_test.go:680: Retrieved narinfo from S3:1604 StorePath: /build/TestClientSharedPathCommittedMidPush660049111/001/store/1wvw35bvyjbskilhmcxbsbwmbn3nss2m-top1605 URL: nar/0da2j0iz2v8n3lzkhnlww3kh7fxy6s7c8isx5hc9gsdv1fgmm2v0.nar.zst1606 Compression: zstd1607 NarHash: sha256:0da2j0iz2v8n3lzkhnlww3kh7fxy6s7c8isx5hc9gsdv1fgmm2v01608 NarSize: 2241609 References: /build/TestClientSharedPathCommittedMidPush660049111/001/store/2ivkpxkqcyhicv6dsfd2bm781qix08md-shared-dep1610 CA: text:sha256:1yd8hm3x5dimyf49sg4875c2gcpzdzk8bwh81jmgn8r51m1q8qik1611=== NAME TestClientMultipleUploads1612 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1369529074/001/store/74899j86zhxqiy43s8y0ckzwbd1sf4a0-test-file-2.txt1613--- PASS: TestCacheStatsHandler (0.40s)1614=== CONT TestClientErrorHandling/ServerNotAvailable1615--- PASS: TestClientSharedPathCommittedMidPush (0.58s)1616=== CONT TestClientErrorHandling/InvalidAuthToken1617=== CONT TestResolveDBConnectionString/flag_wins1618=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1619=== CONT TestResolveDBConnectionString/nothing_configured1620=== CONT TestResolveDBConnectionString/missing_file_is_an_error1621=== CONT TestResolveDBConnectionString/file_when_flag_empty1622=== CONT TestCacheConfigHandler/full_config,_no_issuer1623=== CONT TestCacheConfigHandler/no_signing_keys1624=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1625=== CONT TestCacheConfigHandler/no_cache_url_configured1626--- PASS: TestResolveDBConnectionString (0.00s)1627 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1628 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1629 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1630 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1631 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1632--- PASS: TestCacheConfigHandler (0.00s)1633 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1634 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1635 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1636 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1637=== NAME TestClientCADerivations1638 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations705937531/001/store/psp24zvq3adp5d6fyvbs4y93n6gzpzc8-ca-test1639=== RUN TestService_RequireScope_OIDC/builder_may_write1640=== PAUSE TestService_RequireScope_OIDC/builder_may_write1641=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1642=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin16432026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1644=== RUN TestService_RequireScope_OIDC/ops_may_admin1645=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1646=== RUN TestService_RequireScope_OIDC/ops_may_not_write1647=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1648=== RUN TestService_RequireScope_OIDC/reader_may_not_write1649=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1650=== RUN TestService_RequireScope_OIDC/static_token_may_admin1651=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1652=== RUN TestService_RequireScope_OIDC/static_token_may_write1653=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1654=== RUN TestService_RequireScope_OIDC/reader_may_read1655=== PAUSE TestService_RequireScope_OIDC/reader_may_read1656=== RUN TestService_RequireScope_OIDC/writer_implies_read1657=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1658=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1659=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1660=== CONT TestService_RequireScope_OIDC/builder_may_write1661=== CONT TestService_RequireScope_OIDC/static_token_may_admin1662=== CONT TestService_RequireScope_OIDC/reader_may_read1663=== CONT TestService_RequireScope_OIDC/ops_may_not_write1664=== CONT TestService_RequireScope_OIDC/writer_implies_read1665=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1666=== CONT TestService_RequireScope_OIDC/static_token_may_write1667=== CONT TestService_RequireScope_OIDC/reader_may_not_write1668=== CONT TestService_RequireScope_OIDC/ops_may_admin1669=== CONT TestService_RequireScope_OIDC/builder_may_not_admin16702026/10/01 10:41:31 INFO lead: acquired remote=192.0.2.1:12341671--- PASS: TestService_RequireScope_OIDC (0.52s)1672 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1673 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1674 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1675 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1676 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1677 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1678 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1679 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1680 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1681 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)16822026/10/01 10:41:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16832026/10/01 10:41:31 INFO Uploading faaz2i1p0b1c46ij9shcpvxivc8p94s8-test-file.txt (152B)1684=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token16852026/10/01 10:41:31 INFO lead: released remote=192.0.2.1:12341686=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1687--- PASS: TestLeadElectsOneAndHandsOver (0.62s)1688=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1689=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1690=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1691=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1692=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured16932026/10/01 10:41:31 WARN Failed to register uploaded object key=faaz2i1p0b1c46ij9shcpvxivc8p94s8.ls error="server returned 404: 404 page not found\n"1694=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured16952026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1696=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1697=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16982026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1699=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured17002026/10/01 10:41:31 INFO Signed narinfos id=1 count=11701=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17022026/10/01 10:41:31 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]17032026/10/01 10:41:31 INFO Uploading 1 narinfos17042026/10/01 10:41:31 WARN Authentication failed token_preview=eyJhbGciOi...YubJJADxUQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]17052026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1706--- PASS: TestService_AuthMiddleware_OIDC (0.45s)1707 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1708 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1709 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1710 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)17112026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/1/complete17122026/10/01 10:41:31 WARN Failed to register uploaded object key=faaz2i1p0b1c46ij9shcpvxivc8p94s8.narinfo error="server returned 404: 404 page not found\n"17132026/10/01 10:41:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17142026/10/01 10:41:31 INFO Uploading lvcxnvg942lp91ily5k8q5xx4ic5r24i-unpinned-file.txt (128B)17152026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17162026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17172026/10/01 10:41:31 INFO Signed narinfos id=2 count=117182026/10/01 10:41:31 WARN Failed to register uploaded object key=lvcxnvg942lp91ily5k8q5xx4ic5r24i.ls error="server returned 404: 404 page not found\n"17192026/10/01 10:41:31 INFO Uploading 1 narinfos17202026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/2/complete17212026/10/01 10:41:31 WARN Failed to register uploaded object key=lvcxnvg942lp91ily5k8q5xx4ic5r24i.narinfo error="server returned 404: 404 page not found\n"17222026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes1723--- PASS: TestService_ReadScope_PublicByDefault (0.36s)17242026/10/01 10:41:31 INFO Upload complete. (52ms)17252026/10/01 10:41:31 INFO Upload complete. (69ms)17262026/10/01 10:41:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17272026/10/01 10:41:31 INFO Uploading 3vqzlzqj76irlvwzm0zdxwl9j9c88kl7-test-script (136B)17282026/10/01 10:41:31 WARN Failed to register uploaded object key=3vqzlzqj76irlvwzm0zdxwl9j9c88kl7.ls error="server returned 404: 404 page not found\n"17292026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17302026/10/01 10:41:31 WARN Failed to register uploaded object key=log/mnh8gldzi17z115hfi081gziyvzm4qz3-test-script.drv error="server returned 404: 404 page not found\n"17312026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17322026/10/01 10:41:31 INFO Signed narinfos id=1 count=117332026/10/01 10:41:31 INFO Uploading 1 narinfos17342026/10/01 10:41:31 INFO Received push request method=POST path=/api/pushes17352026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/1/complete17362026/10/01 10:41:31 WARN Failed to register uploaded object key=3vqzlzqj76irlvwzm0zdxwl9j9c88kl7.narinfo error="server returned 404: 404 page not found\n"17372026/10/01 10:41:31 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/present1738=== NAME TestClientCADerivations1739 client_ca_test.go:139: Found 1 dependencies (including self)17402026/10/01 10:41:31 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17412026/10/01 10:41:31 INFO Uploading 74899j86zhxqiy43s8y0ckzwbd1sf4a0-test-file-2.txt (160B)17422026/10/01 10:41:31 INFO Uploading a63b1alfki95vkdyhj49yda8f13zhijj-test-file-0.txt (160B)17432026/10/01 10:41:31 INFO Uploading k821n77q754k088hsnbim6civd3d5cx2-test-file-1.txt (160B)17442026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17452026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17462026/10/01 10:41:31 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17472026/10/01 10:41:31 INFO Upload complete. (67ms)17482026/10/01 10:41:31 WARN Failed to register uploaded object key=a63b1alfki95vkdyhj49yda8f13zhijj.ls error="server returned 404: 404 page not found\n"17492026/10/01 10:41:31 WARN Failed to register uploaded object key=k821n77q754k088hsnbim6civd3d5cx2.ls error="server returned 404: 404 page not found\n"17502026/10/01 10:41:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17512026/10/01 10:41:31 WARN Failed to register uploaded object key=74899j86zhxqiy43s8y0ckzwbd1sf4a0.ls error="server returned 404: 404 page not found\n"17522026/10/01 10:41:31 INFO Signed narinfos id=1 count=317532026/10/01 10:41:31 INFO Uploading 3 narinfos17542026/10/01 10:41:31 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17552026/10/01 10:41:31 WARN mTLS auth: bound subjects configured but subject DN unavailable17562026/10/01 10:41:31 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1757--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.38s)1758=== NAME TestClientWithDependencies1759 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4141536189/001/store) requires matching store prefix17602026/10/01 10:41:31 WARN Failed to register uploaded object key=k821n77q754k088hsnbim6civd3d5cx2.narinfo error="server returned 404: 404 page not found\n"17612026/10/01 10:41:31 WARN Failed to register uploaded object key=a63b1alfki95vkdyhj49yda8f13zhijj.narinfo error="server returned 404: 404 page not found\n"1762--- PASS: TestClientWithDependencies (0.61s)17632026/10/01 10:41:31 INFO Received complete push request method=POST path=/api/pushes/1/complete17642026/10/01 10:41:31 WARN Failed to register uploaded object key=74899j86zhxqiy43s8y0ckzwbd1sf4a0.narinfo error="server returned 404: 404 page not found\n"17652026/10/01 10:41:31 INFO All 1 paths already cached1766=== NAME TestClientIntegration1767 client_integration_test.go:312: Retrieved narinfo from S3:1768 StorePath: /build/TestClientIntegration1286235400/002/store/faaz2i1p0b1c46ij9shcpvxivc8p94s8-test-file.txt1769 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1770 Compression: zstd1771 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11772 NarSize: 1521773 References: 1774 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11775 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1776 client_integration_test.go:313: Decompressed .ls content (64 bytes):1777 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1778 client_integration_test.go:316: Testing garbage collection...17792026/10/01 10:41:31 INFO Upload complete. (64ms)1780=== NAME TestClientMultipleUploads1781 client_integration_test.go:369: Uploaded 3 paths in 98.218408ms17822026/10/01 10:41:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures17832026/10/01 10:41:31 INFO Garbage collection started1784--- PASS: TestClientMultipleUploads (0.62s)1785--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.50s)17862026/10/01 10:41:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.658678ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17872026/10/01 10:41:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures17882026/10/01 10:41:31 INFO Garbage collection started17892026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=017902026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period17912026/10/01 10:41:31 INFO Aborted multipart uploads count=0 kept=017922026/10/01 10:41:31 WARN Force mode enabled - objects will be deleted immediately without grace period17932026/10/01 10:41:32 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=017942026/10/01 10:41:32 INFO Vacuumed table table=pending_closures17952026/10/01 10:41:32 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=017962026/10/01 10:41:32 INFO Vacuumed table table=pending_objects17972026/10/01 10:41:32 INFO Vacuumed table table=multipart_uploads17982026/10/01 10:41:32 INFO Received uploads request method=POST path=/api/pending_closures17992026/10/01 10:41:32 INFO Vacuumed table table=closures18002026/10/01 10:41:32 INFO Vacuumed table table=pending_closures18012026/10/01 10:41:32 INFO Vacuumed table table=objects18022026/10/01 10:41:32 INFO Vacuumed table table=pending_objects18032026/10/01 10:41:32 INFO Vacuumed table table=multipart_uploads18042026/10/01 10:41:32 INFO Vacuumed table table=closures18052026/10/01 10:41:32 INFO Vacuumed table table=objects18062026/10/01 10:41:32 INFO Received uploads request method=POST path=/api/pending_closures18072026/10/01 10:41:32 INFO Aborted multipart uploads count=0 kept=018082026/10/01 10:41:32 WARN Force mode enabled - objects will be deleted immediately without grace period18092026/10/01 10:41:32 INFO Received push request method=POST path=/api/pushes18102026/10/01 10:41:32 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=018112026/10/01 10:41:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18122026/10/01 10:41:32 INFO Uploading psp24zvq3adp5d6fyvbs4y93n6gzpzc8-ca-test (144B)18132026/10/01 10:41:32 INFO Vacuumed table table=pending_closures18142026/10/01 10:41:32 INFO Vacuumed table table=pending_objects18152026/10/01 10:41:32 INFO Vacuumed table table=multipart_uploads18162026/10/01 10:41:32 INFO Vacuumed table table=closures18172026/10/01 10:41:32 INFO Vacuumed table table=objects18182026/10/01 10:41:32 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18192026/10/01 10:41:32 WARN Failed to register uploaded object key=psp24zvq3adp5d6fyvbs4y93n6gzpzc8.ls error="server returned 404: 404 page not found\n"18202026/10/01 10:41:32 WARN Failed to register uploaded object key=log/yj0gjkslcvvqxyc3gnf8ga88iq81cqw8-ca-test.drv error="server returned 404: 404 page not found\n"18212026/10/01 10:41:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18222026/10/01 10:41:32 INFO Signed narinfos id=1 count=118232026/10/01 10:41:32 INFO Uploading 1 narinfos18242026/10/01 10:41:32 INFO Received uploads request method=POST path=/api/pending_closures18252026/10/01 10:41:32 INFO Received complete push request method=POST path=/api/pushes/1/complete18262026/10/01 10:41:32 WARN Failed to register uploaded object key=psp24zvq3adp5d6fyvbs4y93n6gzpzc8.narinfo error="server returned 404: 404 page not found\n"18272026/10/01 10:41:32 INFO Upload complete. (97ms)18282026/10/01 10:41:32 INFO Aborted multipart uploads count=0 kept=018292026/10/01 10:41:32 WARN Force mode enabled - objects will be deleted immediately without grace period1830=== NAME TestClientCADerivations1831 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations705937531/001/store/psp24zvq3adp5d6fyvbs4y93n6gzpzc8-ca-test1832 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1833 Compression: zstd1834 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1835 NarSize: 1441836 References: 1837 Deriver: /build/TestClientCADerivations705937531/001/store/yj0gjkslcvvqxyc3gnf8ga88iq81cqw8-ca-test.drv1838 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1839 client_ca_test.go:185: Checking for realisation files in S3...1840 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1841 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18422026/10/01 10:41:32 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=018432026/10/01 10:41:32 INFO Vacuumed table table=pending_closures18442026/10/01 10:41:32 INFO Vacuumed table table=pending_objects18452026/10/01 10:41:32 INFO Vacuumed table table=multipart_uploads18462026/10/01 10:41:32 INFO Vacuumed table table=closures18472026/10/01 10:41:32 INFO Vacuumed table table=objects1848--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1849 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.35s)1850 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.36s)18512026/10/01 10:41:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.467246ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18522026/10/01 10:41:32 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1853=== NAME TestClientCADerivations1854 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1855 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1856 error: binary cache 's3://bucket75?endpoint=http://localhost:36867®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations705937531/001/store'1857 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11858--- PASS: TestClientCADerivations (0.89s)18592026/10/01 10:41:32 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1860--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1861 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1862 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1863 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.70s)1864=== NAME TestOrphanedObjectsGCStressTest1865 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1866 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18672026/10/01 10:41:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.151986ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1868 orphaned_objects_gc_test.go:509: Stress test completed successfully:1869 orphaned_objects_gc_test.go:510: - Active objects preserved: 201870 orphaned_objects_gc_test.go:511: - Objects deleted: 2101871 orphaned_objects_gc_test.go:512: - Total GC'd: 2101872--- PASS: TestOrphanedObjectsGCStressTest (2.65s)1873--- PASS: TestPendingClosureWriteTimeout (0.09s)1874 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1875 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1876 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1877 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.30s)18782026/10/01 10:41:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.756520825s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18792026/10/01 10:41:33 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018802026/10/01 10:41:33 INFO Received create pin request method=POST path=/api/pins/myapp18812026/10/01 10:41:33 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3365888316/001/store/zqq8m9i7rm3zb5gp29lzm07qywjjawfp-pinned-file.txt narinfo_key=zqq8m9i7rm3zb5gp29lzm07qywjjawfp.narinfo18822026/10/01 10:41:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures18832026/10/01 10:41:33 INFO Garbage collection started18842026/10/01 10:41:33 INFO Aborted multipart uploads count=0 kept=018852026/10/01 10:41:33 WARN Force mode enabled - objects will be deleted immediately without grace period18862026/10/01 10:41:33 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=018872026/10/01 10:41:33 INFO Vacuumed table table=pending_closures18882026/10/01 10:41:33 INFO Vacuumed table table=pending_objects18892026/10/01 10:41:33 INFO Vacuumed table table=multipart_uploads18902026/10/01 10:41:33 INFO Vacuumed table table=closures18912026/10/01 10:41:33 INFO Vacuumed table table=objects18922026/10/01 10:41:33 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01893=== NAME TestClientIntegration1894 client_integration_test.go:323: Objects in database after GC:1895 client_integration_test.go:323: Successfully deleted all objects with GC --force1896--- PASS: TestClientIntegration (2.72s)18972026/10/01 10:41:34 WARN Rate limiter enabled after throttle name=s3-test rate=518982026/10/01 10:41:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1899=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1900 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101901 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001902--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.17s)1903--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.91s)19042026/10/01 10:41:35 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-config19052026/10/01 10:41:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.838229ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19062026/10/01 10:41:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.000147ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1907--- PASS: TestConnectWaitsForAPeerMigration (5.18s)1908=== NAME TestPinProtectsFromGC1909 client_integration_test.go:840: Pin successfully protected closure from garbage collection1910--- PASS: TestPinProtectsFromGC (4.72s)19112026/10/01 10:41:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=815.146776ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19122026/10/01 10:41:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.441588132s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19132026/10/01 10:41:36 INFO Aborted multipart uploads count=1 kept=019142026/10/01 10:41:36 INFO Received cleanup request method=DELETE path=/api/pending_closures19152026/10/01 10:41:36 INFO Aborted multipart uploads count=1 kept=01916--- PASS: TestPendingCleanupUsesOneCutoff (6.66s)19172026/10/01 10:41:38 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"19182026/10/01 10:41:38 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-config19192026/10/01 10:41:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.837497ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19202026/10/01 10:41:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.762402ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19212026/10/01 10:41:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=727.504545ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19222026/10/01 10:41:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.634037766s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19232026/10/01 10:41:41 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_closures19242026/10/01 10:41:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.36863ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19252026/10/01 10:41:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.797123ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19262026/10/01 10:41:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=745.948202ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19272026/10/01 10:41:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.541209927s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1928--- PASS: TestClientErrorHandling (0.00s)1929 --- PASS: TestClientErrorHandling/InvalidStorePath (0.37s)1930 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.46s)1931 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.48s)1932PASS19332026-10-01 10:41:44.579 UTC [129] LOG: received smart shutdown request19342026-10-01 10:41:44.584 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 119352026-10-01 10:41:44.596 UTC [134] LOG: shutting down19362026-10-01 10:41:44.597 UTC [134] LOG: checkpoint starting: shutdown immediate19372026-10-01 10:41:46.582 UTC [134] LOG: checkpoint complete: wrote 10962 buffers (66.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.304 s, sync=1.627 s, total=1.986 s; sync files=29656, longest=0.003 s, average=0.001 s; distance=410252 kB, estimate=410252 kB; lsn=0/1A8090D8, redo lsn=0/1A8090D819382026-10-01 10:41:46.669 UTC [129] LOG: database system is shut down1939Running OIDC tests...1940=== RUN TestAudienceForIssuer1941=== PAUSE TestAudienceForIssuer1942=== RUN TestGlobMatch1943=== PAUSE TestGlobMatch1944=== RUN TestValidateToken_ValidToken1945=== PAUSE TestValidateToken_ValidToken1946=== RUN TestValidateToken_WrongAudience1947=== PAUSE TestValidateToken_WrongAudience1948=== RUN TestValidateToken_Expired1949=== PAUSE TestValidateToken_Expired1950=== RUN TestValidateToken_BoundClaimsMismatch1951=== PAUSE TestValidateToken_BoundClaimsMismatch1952=== RUN TestValidateToken_BoundSubjectMismatch1953=== PAUSE TestValidateToken_BoundSubjectMismatch1954=== RUN TestValidateToken_MultipleProviders1955=== PAUSE TestValidateToken_MultipleProviders1956=== RUN TestValidateToken_NoMatchingProvider1957=== PAUSE TestValidateToken_NoMatchingProvider1958=== RUN TestValidateToken_KubernetesServiceAccount1959=== PAUSE TestValidateToken_KubernetesServiceAccount1960=== RUN TestNewValidator_KubernetesRequiresCA1961=== PAUSE TestNewValidator_KubernetesRequiresCA1962=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1963=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1964=== RUN TestPins_ReservedForMatchingRule1965=== PAUSE TestPins_ReservedForMatchingRule1966=== RUN TestPins_TopLevelShorthand1967=== PAUSE TestPins_TopLevelShorthand1968=== RUN TestPins_ConfigValidation1969=== PAUSE TestPins_ConfigValidation1970=== RUN TestScopes_LegacyProviderDefaultsToWrite1971=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1972=== RUN TestScopes_Rules1973=== PAUSE TestScopes_Rules1974=== RUN TestScopes_ConfigValidation1975=== PAUSE TestScopes_ConfigValidation1976=== CONT TestAudienceForIssuer1977=== CONT TestValidateToken_KubernetesServiceAccount1978=== CONT TestValidateToken_WrongAudience1979--- PASS: TestAudienceForIssuer (0.00s)1980=== CONT TestValidateToken_ValidToken1981=== CONT TestGlobMatch1982=== RUN TestGlobMatch/foo_foo1983=== PAUSE TestGlobMatch/foo_foo1984=== RUN TestGlobMatch/foo_bar1985=== PAUSE TestGlobMatch/foo_bar1986=== RUN TestGlobMatch/*_1987=== PAUSE TestGlobMatch/*_1988=== RUN TestGlobMatch/*_anything1989=== PAUSE TestGlobMatch/*_anything1990=== RUN TestGlobMatch/foo*_foo1991=== PAUSE TestGlobMatch/foo*_foo1992=== RUN TestGlobMatch/foo*_foobar1993=== PAUSE TestGlobMatch/foo*_foobar1994=== CONT TestValidateToken_BoundClaimsMismatch1995=== CONT TestPins_ConfigValidation1996=== CONT TestScopes_ConfigValidation1997=== CONT TestScopes_Rules1998=== CONT TestValidateToken_NoMatchingProvider1999=== CONT TestValidateToken_MultipleProviders2000=== CONT TestScopes_LegacyProviderDefaultsToWrite2001=== CONT TestValidateToken_BoundSubjectMismatch2002=== CONT TestValidateToken_Expired2003=== CONT TestPins_ReservedForMatchingRule2004=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2005=== CONT TestPins_TopLevelShorthand2006=== CONT TestNewValidator_KubernetesRequiresCA2007=== RUN TestGlobMatch/foo*_bar2008=== PAUSE TestGlobMatch/foo*_bar2009--- PASS: TestScopes_ConfigValidation (0.00s)2010--- PASS: TestPins_ConfigValidation (0.00s)2011=== RUN TestGlobMatch/*bar_bar2012=== PAUSE TestGlobMatch/*bar_bar2013=== RUN TestGlobMatch/*bar_foobar2014=== PAUSE TestGlobMatch/*bar_foobar2015=== RUN TestGlobMatch/*bar_foo2016=== PAUSE TestGlobMatch/*bar_foo2017=== RUN TestGlobMatch/foo*bar_foobar2018=== PAUSE TestGlobMatch/foo*bar_foobar2019=== RUN TestGlobMatch/foo*bar_foo123bar2020=== PAUSE TestGlobMatch/foo*bar_foo123bar2021=== RUN TestGlobMatch/foo*bar_foobarbaz2022=== PAUSE TestGlobMatch/foo*bar_foobarbaz2023=== RUN TestGlobMatch/*/*_foo/bar2024=== PAUSE TestGlobMatch/*/*_foo/bar2025=== RUN TestGlobMatch/*/*_foo2026=== PAUSE TestGlobMatch/*/*_foo2027=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2028=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2029=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02030=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02031=== RUN TestGlobMatch/refs/*/main_refs/heads/main2032=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2033=== RUN TestGlobMatch/fo?_foo2034=== PAUSE TestGlobMatch/fo?_foo2035=== RUN TestGlobMatch/fo?_fo2036=== PAUSE TestGlobMatch/fo?_fo2037=== RUN TestGlobMatch/fo?_fooo2038=== PAUSE TestGlobMatch/fo?_fooo2039=== RUN TestGlobMatch/?oo_foo2040=== PAUSE TestGlobMatch/?oo_foo2041=== RUN TestGlobMatch/?oo_boo2042=== PAUSE TestGlobMatch/?oo_boo2043=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2044=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2045=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2046=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2047=== CONT TestGlobMatch/foo_foo2048=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2049=== CONT TestGlobMatch/*/*_foo/bar2050=== CONT TestGlobMatch/foo*bar_foobarbaz2051=== CONT TestGlobMatch/?oo_boo2052=== CONT TestGlobMatch/?oo_foo2053=== CONT TestGlobMatch/fo?_fooo2054=== CONT TestGlobMatch/*bar_foobar2055=== CONT TestGlobMatch/*bar_bar2056=== CONT TestGlobMatch/fo?_fo2057=== CONT TestGlobMatch/foo*_foobar2058=== CONT TestGlobMatch/fo?_foo2059=== CONT TestGlobMatch/refs/*/main_refs/heads/main2060=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02061=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2062=== CONT TestGlobMatch/*/*_foo2063=== CONT TestGlobMatch/foo*bar_foo123bar2064=== CONT TestGlobMatch/foo*bar_foobar2065=== CONT TestGlobMatch/*bar_foo2066=== CONT TestGlobMatch/foo*_bar2067=== CONT TestGlobMatch/foo*_foo2068=== CONT TestGlobMatch/*_2069=== CONT TestGlobMatch/*_anything2070=== CONT TestGlobMatch/foo_bar2071=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2072--- PASS: TestGlobMatch (0.01s)2073 --- PASS: TestGlobMatch/foo_foo (0.00s)2074 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2075 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2076 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2077 --- PASS: TestGlobMatch/?oo_boo (0.00s)2078 --- PASS: TestGlobMatch/?oo_foo (0.00s)2079 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2080 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2081 --- PASS: TestGlobMatch/*bar_bar (0.00s)2082 --- PASS: TestGlobMatch/fo?_fo (0.00s)2083 --- PASS: TestGlobMatch/fo?_foo (0.00s)2084 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2085 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2086 --- PASS: TestGlobMatch/*/*_foo (0.00s)2087 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2088 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2089 --- PASS: TestGlobMatch/*bar_foo (0.00s)2090 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2091 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2092 --- PASS: TestGlobMatch/foo*_bar (0.00s)2093 --- PASS: TestGlobMatch/foo*_foo (0.00s)2094 --- PASS: TestGlobMatch/*_ (0.00s)2095 --- PASS: TestGlobMatch/*_anything (0.00s)2096 --- PASS: TestGlobMatch/foo_bar (0.00s)2097 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)20982026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38397/oidc2099--- PASS: TestValidateToken_WrongAudience (0.03s)21002026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39673/oidc21012026/10/01 10:41:48 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3618121022026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32979/oidc2103--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)2104--- PASS: TestValidateToken_Expired (0.04s)2105--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)21062026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43999/oidc2107--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.05s)21082026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37219/oidc2109--- PASS: TestPins_TopLevelShorthand (0.07s)21102026/10/01 10:41:48 http: TLS handshake error from 127.0.0.1:55002: remote error: tls: bad certificate2111--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)21122026/10/01 10:41:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40383/oidc21132026/10/01 10:41:48 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45871/oidc2114--- PASS: TestValidateToken_MultipleProviders (0.09s)21152026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33193/oidc2116--- PASS: TestScopes_Rules (0.11s)21172026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41587/oidc2118--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)21192026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44809/oidc2120--- PASS: TestValidateToken_ValidToken (0.12s)21212026/10/01 10:41:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38755/oidc2122--- PASS: TestPins_ReservedForMatchingRule (0.13s)21232026/10/01 10:41:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35737/oidc2124--- PASS: TestValidateToken_NoMatchingProvider (0.14s)21252026/10/01 10:41:48 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232126--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.18s)2127PASS2128Running hook tests...2129=== RUN TestSendPathsEmpty2130=== PAUSE TestSendPathsEmpty2131=== RUN TestQueueEnqueueAndFetch2132=== PAUSE TestQueueEnqueueAndFetch2133=== RUN TestQueueDeduplication2134=== PAUSE TestQueueDeduplication2135=== RUN TestQueueRemove2136=== PAUSE TestQueueRemove2137=== RUN TestQueueFetchBatchLimit2138=== PAUSE TestQueueFetchBatchLimit2139=== RUN TestQueueRetryMovesToBack2140=== PAUSE TestQueueRetryMovesToBack2141=== RUN TestQueueFetchRemoveLifecycle2142=== PAUSE TestQueueFetchRemoveLifecycle2143=== RUN TestQueueConcurrentWriters2144=== PAUSE TestQueueConcurrentWriters2145=== RUN TestQueueRemoveLargeClosure2146=== PAUSE TestQueueRemoveLargeClosure2147=== RUN TestServerClientIntegration2148=== PAUSE TestServerClientIntegration2149=== RUN TestServerQueueError2150=== PAUSE TestServerQueueError2151=== RUN TestGetListenerSocketActivation2152 server_test.go:210: === RUN TestGetListenerSocketActivation2153 --- PASS: TestGetListenerSocketActivation (0.00s)2154 PASS2155 2156--- PASS: TestGetListenerSocketActivation (0.01s)2157=== RUN TestDrainIsolatesPoisonPath2158=== PAUSE TestDrainIsolatesPoisonPath2159=== RUN TestRunNotBlockedByPoisonHead2160=== PAUSE TestRunNotBlockedByPoisonHead2161=== RUN TestDrainGivesUpWhenServerDown2162=== PAUSE TestDrainGivesUpWhenServerDown2163=== RUN TestFailedPathPrunedByLaterClosure2164=== PAUSE TestFailedPathPrunedByLaterClosure2165=== RUN TestWorkerUploadsAndRemoves2166=== PAUSE TestWorkerUploadsAndRemoves2167=== RUN TestWorkerSkipsGCdPaths2168=== PAUSE TestWorkerSkipsGCdPaths2169=== RUN TestWorkerPrunesClosureDeps2170=== PAUSE TestWorkerPrunesClosureDeps2171=== RUN TestDrainTimeout2172=== PAUSE TestDrainTimeout2173=== CONT TestSendPathsEmpty2174=== CONT TestServerQueueError2175=== CONT TestDrainTimeout2176--- PASS: TestSendPathsEmpty (0.00s)2177=== CONT TestServerClientIntegration2178=== CONT TestQueueRemoveLargeClosure2179=== CONT TestQueueConcurrentWriters2180=== CONT TestQueueFetchRemoveLifecycle2181=== CONT TestQueueRetryMovesToBack2182=== CONT TestQueueFetchBatchLimit2183=== CONT TestQueueRemove2184=== CONT TestQueueDeduplication21852026/10/01 10:41:48 ERROR Failed to queue paths error="permission denied" count=12186=== CONT TestQueueEnqueueAndFetch2187=== CONT TestWorkerPrunesClosureDeps2188=== CONT TestDrainGivesUpWhenServerDown2189=== CONT TestFailedPathPrunedByLaterClosure2190=== CONT TestWorkerSkipsGCdPaths2191=== CONT TestRunNotBlockedByPoisonHead2192=== CONT TestDrainIsolatesPoisonPath2193=== CONT TestWorkerUploadsAndRemoves2194--- PASS: TestServerQueueError (0.00s)2195--- PASS: TestServerClientIntegration (0.00s)21962026/10/01 10:41:48 INFO Upload queue status pending=221972026/10/01 10:41:48 INFO Uploading batch count=121982026/10/01 10:41:48 INFO Uploading batch count=221992026/10/01 10:41:48 INFO Upload queue status pending=222002026/10/01 10:41:48 INFO Upload queue status pending=222012026/10/01 10:41:48 INFO Uploading batch count=222022026/10/01 10:41:48 INFO Upload queue status pending=322032026/10/01 10:41:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths117676697/002/nonexistent22042026/10/01 10:41:48 INFO Uploading batch count=122052026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=12206--- PASS: TestQueueRemove (0.02s)22072026/10/01 10:41:48 INFO Uploading batch count=42208--- PASS: TestQueueEnqueueAndFetch (0.02s)22092026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=42210--- PASS: TestQueueFetchBatchLimit (0.02s)22112026/10/01 10:41:48 INFO Uploading batch count=222122026/10/01 10:41:48 INFO Uploading batch count=122132026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=122142026/10/01 10:41:48 INFO Uploading batch count=122152026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=222162026/10/01 10:41:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3376462180/002/a22172026/10/01 10:41:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath69485786/002/bbb22182026/10/01 10:41:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3376462180/002/b22192026/10/01 10:41:48 INFO Uploading batch count=12220--- PASS: TestQueueDeduplication (0.02s)2221--- PASS: TestQueueRetryMovesToBack (0.02s)22222026/10/01 10:41:48 INFO Uploading batch count=222232026/10/01 10:41:48 INFO Uploading batch count=12224--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22252026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=222262026/10/01 10:41:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3376462180/002/c22272026/10/01 10:41:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3376462180/002/d22282026/10/01 10:41:48 INFO Uploading batch count=222292026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=222302026/10/01 10:41:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3376462180/002/e22312026/10/01 10:41:48 INFO Uploading batch count=122322026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=12233--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22342026/10/01 10:41:48 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3376462180/002/f22352026/10/01 10:41:48 INFO Uploading batch count=122362026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=122372026/10/01 10:41:48 ERROR Drain finished with paths left in queue remaining=1022382026/10/01 10:41:48 INFO Uploading batch count=122392026/10/01 10:41:48 ERROR Upload failed error="upload failed" count=122402026/10/01 10:41:48 ERROR Drain finished with paths left in queue remaining=12241--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2242--- PASS: TestDrainIsolatesPoisonPath (0.03s)2243--- PASS: TestWorkerPrunesClosureDeps (0.04s)2244--- PASS: TestWorkerSkipsGCdPaths (0.04s)2245--- PASS: TestWorkerUploadsAndRemoves (0.04s)2246--- PASS: TestQueueRemoveLargeClosure (0.10s)22472026/10/01 10:41:48 ERROR Upload failed error="context deadline exceeded" count=222482026/10/01 10:41:48 ERROR Drain finished with paths left in queue remaining=42249--- PASS: TestDrainTimeout (0.22s)2250--- PASS: TestQueueConcurrentWriters (0.38s)22512026/10/01 10:41:49 INFO Uploading batch count=122522026/10/01 10:41:49 INFO Uploading batch count=122532026/10/01 10:41:49 INFO Uploading batch count=122542026/10/01 10:41:49 ERROR Upload failed error="upload failed" count=122552026/10/01 10:41:49 INFO Uploading batch count=122562026/10/01 10:41:49 ERROR Upload failed error="upload failed" count=122572026/10/01 10:41:49 INFO Uploading batch count=122582026/10/01 10:41:49 ERROR Upload failed error="upload failed" count=122592026/10/01 10:41:49 INFO Uploading batch count=122602026/10/01 10:41:49 ERROR Upload failed error="upload failed" count=122612026/10/01 10:41:49 ERROR Drain finished with paths left in queue remaining=12262--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2263PASS