niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #391
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestStreamPushGivesUpOnDeadServer101=== CONT TestFileTokenMissing102=== CONT TestScriptTokenEmptyCommand103--- PASS: TestScriptTokenEmptyCommand (0.00s)104=== CONT TestParsePathInfoJSONMultiplePaths105=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths106=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths107=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths108=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths109=== CONT TestScriptTokenScriptFails1102026/10/07 06:11:57 ERROR Upload failed error="connection refused" count=201112026/10/07 06:11:57 ERROR Server seems unavailable, giving up on batch untried=17112--- PASS: TestFileTokenMissing (0.00s)113=== CONT TestDumpPathSingleFile114=== CONT TestConvertHashToNix32115=== CONT TestScriptTokenBadJSON116=== CONT TestScriptTokenEmptyToken117=== CONT TestScriptTokenCachesUntilRefresh118=== CONT TestScriptTokenNoExpiryRerunsEveryCall119=== CONT TestFileTokenEmpty120=== CONT TestResolveStorePath121=== CONT TestStreamPushIsolatesFailures122=== CONT TestStreamPushBatchesUnderLoad123=== CONT TestStreamPushReportsEveryPath124=== CONT TestShellSplitErrors125=== CONT TestShellSplit126=== CONT TestDoWithRetry_BodyReplayedViaGetBody127=== CONT TestPathInfoCACompatibility128=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess129=== CONT TestRateLimiterFeedback130=== CONT TestParsePathInfoJSON131=== CONT TestGetStorePathHash132=== CONT TestUploadMultipart_SupersededByPeer133=== CONT TestPathInfoHashCompatibility134=== RUN TestConvertHashToNix32/SRI_format_to_Nix32135=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32136=== RUN TestConvertHashToNix32/already_Nix32_format137--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)138=== CONT TestDumpPathWriterError139--- PASS: TestShellSplitErrors (0.00s)140=== PAUSE TestConvertHashToNix32/already_Nix32_format141=== CONT TestDumpPathMatchesNix142=== RUN TestPathInfoCACompatibility/null_ca_field143=== PAUSE TestPathInfoCACompatibility/null_ca_field1442026/10/07 06:11:57 ERROR Upload failed error="bad path" count=3145=== RUN TestPathInfoCACompatibility/old_string_format_-_text146=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text147=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive149=== CONT TestUploadMultipart_PartsInParallel150=== RUN TestRateLimiterFeedback/429_enables_limiter151=== RUN TestPathInfoCACompatibility/new_structured_format_-_text152=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text153=== PAUSE TestRateLimiterFeedback/429_enables_limiter154=== RUN TestParsePathInfoJSON/Nix_format155=== CONT TestEncodeNixBase32WithRealHash156=== RUN TestRateLimiterFeedback/503_enables_limiter157=== RUN TestUploadMultipart_SupersededByPeer/exists158=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)159=== RUN TestConvertHashToNix32/invalid_format160--- PASS: TestShellSplit (0.00s)161=== PAUSE TestParsePathInfoJSON/Nix_format162--- PASS: TestStreamPushReportsEveryPath (0.00s)163=== CONT TestCaseHackSuffix164=== RUN TestGetStorePathHash/valid_store_path165--- PASS: TestFileTokenEmpty (0.00s)1662026/10/07 06:11:57 WARN Rate limiter enabled after throttle name=server-test rate=5167--- PASS: TestEncodeNixBase32WithRealHash (0.00s)168--- PASS: TestStreamPushIsolatesFailures (0.00s)169=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method170=== RUN TestParsePathInfoJSON/Lix_format171--- PASS: TestResolveStorePath (0.00s)172=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method173=== CONT TestStaticToken174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon177=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI179=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512180=== CONT TestFileTokenReadsAndCaches181=== PAUSE TestConvertHashToNix32/invalid_format182=== CONT TestSetClientTLSDoesNotMutateDefaultTransport183=== CONT TestPartSizeForNAR184=== PAUSE TestGetStorePathHash/valid_store_path185=== RUN TestGetStorePathHash/basename_without_hyphen_should_error186=== CONT TestClientSignaturesByStorePath187=== RUN TestPartSizeForNAR/zero_stays_at_minimum188=== CONT TestSetClientTLSErrors189=== CONT TestEncodeNixBase32190=== CONT TestFilterOversizedClosures191=== RUN TestFilterOversizedClosures/no_limit_keeps_everything192=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error193=== PAUSE TestUploadMultipart_SupersededByPeer/exists194--- PASS: TestStaticToken (0.00s)195--- PASS: TestScriptTokenScriptFails (0.01s)196=== PAUSE TestRateLimiterFeedback/503_enables_limiter197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512198=== PAUSE TestParsePathInfoJSON/Lix_format1992026/10/07 06:11:57 WARN Rate limiter enabled after throttle name=server-test rate=5200=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum201=== RUN TestEncodeNixBase32/test_string_hash202=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2032026/10/07 06:11:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40335204=== RUN TestSetClientTLSErrors/missing_cert_file205=== CONT TestStreamPushReportsSignatures206=== RUN TestPartSizeForNAR/small_stays_at_minimum207=== PAUSE TestPartSizeForNAR/small_stays_at_minimum208=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum209=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error210=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error211=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error212=== RUN TestUploadMultipart_SupersededByPeer/missing213=== PAUSE TestUploadMultipart_SupersededByPeer/missing2142026/10/07 06:11:57 WARN Rate limiter backed off name=server-test rate=5215--- PASS: TestClientSignaturesByStorePath (0.00s)2162026/10/07 06:11:57 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40335217--- PASS: TestScriptTokenBadJSON (0.01s)218=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2192026/10/07 06:11:57 ERROR Upload failed error=boom count=1220=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter221=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter222=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter223=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter224=== CONT TestStreamPushRequestLine225=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive226=== CONT TestPathInfoCACompatibility/old_string_format_-_text227=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun2282026/10/07 06:11:57 ERROR Upload failed error=boom count=1229=== CONT TestConvertHashToNix32/SRI_format_to_Nix32230=== CONT TestConvertHashToNix32/already_Nix32_format231=== CONT TestConvertHashToNix32/invalid_format232=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512233=== RUN TestParsePathInfoJSON/empty_input234=== PAUSE TestEncodeNixBase32/test_string_hash235=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything236=== PAUSE TestSetClientTLSErrors/missing_cert_file237=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum238=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped239=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI240=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts241=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts242=== RUN TestPartSizeForNAR/1_TiB243=== PAUSE TestPartSizeForNAR/1_TiB244=== CONT TestSetClientTLS245=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths246=== CONT TestPathInfoCACompatibility/new_structured_format_-_text247=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2482026/10/07 06:11:57 INFO Garbage collection started249=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error250--- PASS: TestScriptTokenEmptyToken (0.01s)2512026/10/07 06:11:57 INFO Garbage collection started252=== CONT TestPathInfoCACompatibility/null_ca_field253=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method254=== CONT TestGetStorePathHash/basename_without_hyphen_should_error255=== CONT TestRegisterUploadedObjectReusesConnections256=== CONT TestRateLimiterFeedback/429_enables_limiter257=== CONT TestUploadMultipart_SupersededByPeer/exists258=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)259=== PAUSE TestParsePathInfoJSON/empty_input260=== RUN TestParsePathInfoJSON/whitespace_only261=== PAUSE TestParsePathInfoJSON/whitespace_only262=== RUN TestParsePathInfoJSON/invalid_JSON263=== PAUSE TestParsePathInfoJSON/invalid_JSON264=== RUN TestEncodeNixBase32/empty_input265=== PAUSE TestEncodeNixBase32/empty_input266=== RUN TestSetClientTLSErrors/missing_key_file267=== PAUSE TestSetClientTLSErrors/missing_key_file268=== RUN TestSetClientTLSErrors/missing_ca_file269=== PAUSE TestSetClientTLSErrors/missing_ca_file270=== RUN TestSetClientTLSErrors/invalid_ca_file271=== PAUSE TestSetClientTLSErrors/invalid_ca_file272=== CONT TestRateLimiterFeedback/503_enables_limiter2732026/10/07 06:11:57 WARN Rate limiter enabled after throttle name=server-test rate=52742026/10/07 06:11:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:45989275=== RUN TestSetClientTLS/rejects_connection_without_client_cert276=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped277=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon278=== RUN TestPartSizeForNAR/5_TiB_S3_max_object279=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error280=== CONT TestGetStorePathHash/valid_store_path281--- PASS: TestFileTokenReadsAndCaches (0.00s)282=== CONT TestUploadMultipart_SupersededByPeer/missing283=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter284=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2852026/10/07 06:11:57 WARN Rate limiter backed off name=server-test rate=5286=== CONT TestParsePathInfoJSON/invalid_JSON287=== CONT TestParsePathInfoJSON/whitespace_only288=== CONT TestParsePathInfoJSON/empty_input289=== CONT TestParsePathInfoJSON/Lix_format290=== CONT TestEncodeNixBase32/test_string_hash291=== CONT TestSetClientTLSErrors/missing_cert_file292=== CONT TestEncodeNixBase32/empty_input293=== CONT TestSetClientTLSErrors/invalid_ca_file294=== CONT TestSetClientTLSErrors/missing_ca_file295--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)296--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)297--- PASS: TestDoServerRequestAttachesToken (0.05s)298--- PASS: TestStreamPushReportsSignatures (0.00s)299--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)300--- PASS: TestDumpPathSingleFile (0.05s)301--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)302=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert303=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA304=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA305=== RUN TestSetClientTLS/preserves_debug_logging_transport306=== PAUSE TestSetClientTLS/preserves_debug_logging_transport307=== CONT TestParsePathInfoJSON/Nix_format308=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object309=== RUN TestPartSizeForNAR/capped_at_5_GiB310=== PAUSE TestPartSizeForNAR/capped_at_5_GiB311=== CONT TestPartSizeForNAR/zero_stays_at_minimum312=== CONT TestSetClientTLS/rejects_connection_without_client_cert313=== CONT TestSetClientTLSErrors/missing_key_file3142026/10/07 06:11:57 WARN Rate limiter enabled after throttle name=server-test rate=53152026/10/07 06:11:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:371393162026/10/07 06:11:57 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0317=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum318=== CONT TestPartSizeForNAR/small_stays_at_minimum319=== CONT TestSetClientTLS/preserves_debug_logging_transport3202026/10/07 06:11:57 WARN Rate limiter backed off name=server-test rate=5321--- PASS: TestConvertHashToNix32 (0.01s)322 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)323 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)324 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)325--- PASS: TestParsePathInfoJSON (0.05s)326 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)327 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)328 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)329 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)330 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)331=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA332--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)333 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3352026/10/07 06:11:57 WARN Garbage collection finished on another replica. Its statistics are not available here336=== CONT TestPartSizeForNAR/5_TiB_S3_max_object337=== CONT TestPartSizeForNAR/1_TiB338=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts339=== RUN TestFilterOversizedClosures/all_closures_skipped340=== CONT TestPartSizeForNAR/capped_at_5_GiB341--- PASS: TestGetStorePathHash (0.04s)342 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)343 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)345 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)346--- PASS: TestPathInfoCACompatibility (0.00s)347 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)348 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)349 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)350 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)351 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)352=== PAUSE TestFilterOversizedClosures/all_closures_skipped353=== CONT TestFilterOversizedClosures/no_limit_keeps_everything354=== CONT TestFilterOversizedClosures/all_closures_skipped3552026/10/07 06:11:57 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=50356--- PASS: TestPathInfoHashCompatibility (0.04s)357 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)358 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)359 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)360 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)361=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3622026/10/07 06:11:57 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=2000363--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)364 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)365 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)366--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)367--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)368--- PASS: TestSetClientTLSErrors (0.04s)369 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)370 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)371 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)372 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)373--- PASS: TestRateLimiterFeedback (0.04s)374 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)375 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)376 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)378--- PASS: TestPartSizeForNAR (0.04s)379 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)383 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)384 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)385 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)386--- PASS: TestEncodeNixBase32 (0.04s)387 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)388 --- PASS: TestEncodeNixBase32/empty_input (0.00s)389--- PASS: TestFilterOversizedClosures (0.05s)390 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)391 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)392 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)393--- PASS: TestStreamPushRequestLine (0.02s)3942026/10/07 06:11:57 http: TLS handshake error from 127.0.0.1:51276: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.00s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestCaseHackSuffix (0.07s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)401--- PASS: TestDumpPathWriterError (0.09s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.14s)404--- PASS: TestUploadMultipart_PartsInParallel (0.67s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres3343929319/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres3343929319/data -l logfile start434435/build/postgres3343929319:5432 - no response4362026-10-07 06:11:59.175 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 06:11:59.175 UTC [129] LOG: listening on Unix socket "/build/postgres3343929319/.s.PGSQL.5432"4382026-10-07 06:11:59.181 UTC [136] LOG: database system was shut down at 2026-10-07 06:11:58 UTC4392026-10-07 06:11:59.189 UTC [129] LOG: database system is ready to accept connections440/build/postgres3343929319:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestDeleteClosuresRacingPins478=== PAUSE TestDeleteClosuresRacingPins479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/07 06:11:59 INFO lead: acquired remote=192.0.2.1:12344892026/10/07 06:12:00 INFO lead: released remote=192.0.2.1:12344902026/10/07 06:12:00 INFO lead: acquired remote=192.0.2.1:12344912026/10/07 06:12:01 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (1.86s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/07 06:12:01 INFO lead: acquired remote=192.0.2.1:12344992026-10-07 06:12:02.958 UTC [574] FATAL: terminating connection due to administrator command5002026/10/07 06:12:03 INFO lead: acquired remote=192.0.2.1:12345012026/10/07 06:12:04 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/07 06:12:04 INFO lead: released remote=192.0.2.1:12345032026/10/07 06:12:04 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestMetricsCommit574=== PAUSE TestMetricsCommit575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestObjectStatsLargeCommit588=== PAUSE TestObjectStatsLargeCommit589=== RUN TestOrphanedObjectsGC590=== PAUSE TestOrphanedObjectsGC591=== RUN TestOrphanedObjectsGCStressTest592=== PAUSE TestOrphanedObjectsGCStressTest593=== RUN TestCreatePin_ReservedPins594=== PAUSE TestCreatePin_ReservedPins595=== RUN TestPresentReportsOnlyClosureRoots596=== PAUSE TestPresentReportsOnlyClosureRoots597=== RUN TestPresentRefreshesOnlyStaleClosures598=== PAUSE TestPresentRefreshesOnlyStaleClosures599=== RUN TestPresentNotReportedWhileGCDeletesClosure600=== PAUSE TestPresentNotReportedWhileGCDeletesClosure601=== RUN TestParseSingleRange602=== PAUSE TestParseSingleRange603=== RUN TestProxyHeadersOnlyTrustedOnSocket604=== PAUSE TestProxyHeadersOnlyTrustedOnSocket605=== RUN TestIsValidCachePath606=== PAUSE TestIsValidCachePath607=== RUN TestReadProxyNarinfo608=== PAUSE TestReadProxyNarinfo609=== RUN TestReadProxyNarinfoAlreadyDecompressed610=== PAUSE TestReadProxyNarinfoAlreadyDecompressed611=== RUN TestReadProxyContentNegotiation612=== PAUSE TestReadProxyContentNegotiation613=== RUN TestReadProxyNarStreaming614=== PAUSE TestReadProxyNarStreaming615=== RUN TestReadProxy404616=== PAUSE TestReadProxy404617=== RUN TestReadProxyInvalidPath618=== PAUSE TestReadProxyInvalidPath619=== RUN TestReadProxyHead620=== PAUSE TestReadProxyHead621=== RUN TestReadProxyOutlastsServerWriteTimeout622=== PAUSE TestReadProxyOutlastsServerWriteTimeout623=== RUN TestReadProxyConditionalGet624=== PAUSE TestReadProxyConditionalGet625=== RUN TestReadProxyRootRedirectsToIndexHTML626=== PAUSE TestReadProxyRootRedirectsToIndexHTML627=== RUN TestReadProxyDisabled628=== PAUSE TestReadProxyDisabled629=== RUN TestReadRedirectNar630=== PAUSE TestReadRedirectNar631=== RUN TestReadRedirectKeepsNarinfoProxied632=== PAUSE TestReadRedirectKeepsNarinfoProxied633=== RUN TestReadProxyRangeRequest634=== PAUSE TestReadProxyRangeRequest635=== RUN TestReadRedirectUsesPublicS3URL636=== PAUSE TestReadRedirectUsesPublicS3URL637=== RUN TestPush_OverlappingRootsStoreOneRowPerKey638=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey639=== RUN TestPush_CompleteCommitsEveryRoot640=== PAUSE TestPush_CompleteCommitsEveryRoot641=== RUN TestPush_RepeatedRootCommitsOnce642=== PAUSE TestPush_RepeatedRootCommitsOnce643=== RUN TestPush_CompleteWaitsForCleanupOfThePush644=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush645=== RUN TestPush_RootsAreLockedInByteOrder646=== PAUSE TestPush_RootsAreLockedInByteOrder647=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit648=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit649=== RUN TestPush_RejectsBadRequests650=== PAUSE TestPush_RejectsBadRequests651=== RUN TestPush_SignsNarinfosOfItsPendingObjects652=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects653=== RUN TestRedundantMultipartUpload654=== PAUSE TestRedundantMultipartUpload655=== RUN TestCompleteMultipartUpload_ErrorButObjectExists656=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists657=== RUN TestCompletedNarNotReofferedAcrossClosures658=== PAUSE TestCompletedNarNotReofferedAcrossClosures659=== RUN TestPresignedUploadRegisteredBeforeCommit660=== PAUSE TestPresignedUploadRegisteredBeforeCommit661=== RUN TestService_Rustfstest662=== PAUSE TestService_Rustfstest663=== RUN TestParseSize664=== PAUSE TestParseSize665=== RUN TestSkippedUploadsHandler666=== PAUSE TestSkippedUploadsHandler667=== RUN TestSystemdListenerNotActivated668--- PASS: TestSystemdListenerNotActivated (0.00s)669=== RUN TestWatchdogBeatsWhenHealthy670--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)671=== RUN TestWatchdogSkipsWhenUnhealthy6722026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 06:12:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"682--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)683=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle684=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle685=== RUN TestProxyWriteTimeout686=== PAUSE TestProxyWriteTimeout687=== RUN TestPendingClosureWriteTimeout688=== PAUSE TestPendingClosureWriteTimeout689=== RUN TestIsValidUploadKey690=== PAUSE TestIsValidUploadKey691=== RUN TestUploadHandlersRejectInvalidKeys692=== PAUSE TestUploadHandlersRejectInvalidKeys693=== RUN TestUploadHandlersRejectOversizedBody694=== PAUSE TestUploadHandlersRejectOversizedBody695=== RUN TestService_cleanupPendingClosuresHandler696=== PAUSE TestService_cleanupPendingClosuresHandler697=== RUN TestService_createPendingClosureHandler698=== PAUSE TestService_createPendingClosureHandler699=== RUN TestService_verifyS3Integrity700=== PAUSE TestService_verifyS3Integrity701=== RUN TestCompleteMultipartUnregistered702=== PAUSE TestCompleteMultipartUnregistered703=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT704=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT705=== CONT TestService_AuthMiddleware706=== CONT TestSkippedUploadsHandler707=== CONT TestPush_RepeatedRootCommitsOnce708=== CONT TestPushWaitsForSweepHoldingRow7092026/10/07 06:12:04 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000710=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT711=== CONT TestCompleteMultipartUnregistered712=== CONT TestService_verifyS3Integrity713=== CONT TestService_createPendingClosureHandler714=== CONT TestService_cleanupPendingClosuresHandler715=== CONT TestUploadHandlersRejectOversizedBody716=== CONT TestUploadHandlersRejectInvalidKeys717=== CONT TestIsValidUploadKey718=== CONT TestPendingClosureWriteTimeout719=== CONT TestProxyWriteTimeout720=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle721=== CONT TestReadProxyNarStreaming722=== RUN TestPendingClosureWriteTimeout/empty723=== RUN TestProxyWriteTimeout/narinfo724=== PAUSE TestProxyWriteTimeout/narinfo725=== CONT TestReadProxyNarinfoAlreadyDecompressed726=== CONT TestReadProxyNarinfo727=== CONT TestIsValidCachePath728=== CONT TestProxyHeadersOnlyTrustedOnSocket729=== CONT TestParseSingleRange730=== CONT TestPresentNotReportedWhileGCDeletesClosure731=== CONT TestReadProxy404732=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info733=== RUN TestIsValidUploadKey/narinfo734=== CONT TestReadProxyContentNegotiation735=== PAUSE TestPendingClosureWriteTimeout/empty736=== RUN TestProxyWriteTimeout/1_GiB_nar737=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info738=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal739=== PAUSE TestIsValidUploadKey/narinfo740=== RUN TestIsValidUploadKey/nar_zst741=== RUN TestPendingClosureWriteTimeout/400_objects742=== PAUSE TestProxyWriteTimeout/1_GiB_nar743=== PAUSE TestPendingClosureWriteTimeout/400_objects744=== RUN TestPendingClosureWriteTimeout/670k_objects745=== PAUSE TestPendingClosureWriteTimeout/670k_objects746=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal747=== PAUSE TestIsValidUploadKey/nar_zst748=== RUN TestIsValidUploadKey/nar_xz749=== PAUSE TestIsValidUploadKey/nar_xz750=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key751=== RUN TestIsValidUploadKey/nar_plain752=== PAUSE TestIsValidUploadKey/nar_plain753=== RUN TestIsValidUploadKey/listing754=== PAUSE TestIsValidUploadKey/listing755=== RUN TestIsValidUploadKey/build_log756=== PAUSE TestIsValidUploadKey/build_log757=== RUN TestIsValidUploadKey/build_log_home-manager_file758=== PAUSE TestIsValidUploadKey/build_log_home-manager_file759=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key760=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key761=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key762=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh763=== CONT TestPresentRefreshesOnlyStaleClosures764=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh765=== RUN TestIsValidCachePath/narinfo766=== PAUSE TestIsValidCachePath/narinfo767=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline768=== RUN TestProxyWriteTimeout/10_GiB_nar769=== RUN TestIsValidUploadKey/build_log_plus_in_name770=== RUN TestParseSingleRange/none771=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale772=== PAUSE TestParseSingleRange/none773=== RUN TestParseSingleRange/unknown_unit774=== PAUSE TestParseSingleRange/unknown_unit775=== RUN TestParseSingleRange/multi-range_ignored776=== PAUSE TestParseSingleRange/multi-range_ignored777--- PASS: TestSkippedUploadsHandler (0.09s)778=== CONT TestPresentReportsOnlyClosureRoots779=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars780=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars781=== RUN TestIsValidCachePath/nar_zst782=== PAUSE TestIsValidCachePath/nar_zst783=== RUN TestIsValidCachePath/nar_xz784=== PAUSE TestIsValidCachePath/nar_xz785=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline786=== PAUSE TestProxyWriteTimeout/10_GiB_nar787=== PAUSE TestIsValidUploadKey/build_log_plus_in_name788=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale789=== RUN TestParseSingleRange/malformed_no_dash790=== CONT TestOrphanedObjectsGCStressTest791=== RUN TestIsValidCachePath/nar_bz2792=== PAUSE TestIsValidCachePath/nar_bz2793=== RUN TestIsValidCachePath/nar_uncompressed794=== PAUSE TestIsValidCachePath/nar_uncompressed795=== PAUSE TestParseSingleRange/malformed_no_dash796=== RUN TestParseSingleRange/malformed_both_empty797=== PAUSE TestParseSingleRange/malformed_both_empty798=== RUN TestParseSingleRange/malformed_end_before_start799=== PAUSE TestParseSingleRange/malformed_end_before_start800=== RUN TestParseSingleRange/closed801=== PAUSE TestParseSingleRange/closed802=== RUN TestParseSingleRange/open-ended803=== PAUSE TestParseSingleRange/open-ended804=== RUN TestParseSingleRange/end_clamped_to_size805=== PAUSE TestParseSingleRange/end_clamped_to_size806=== RUN TestParseSingleRange/suffix807=== PAUSE TestParseSingleRange/suffix808=== CONT TestCreatePin_ReservedPins809=== RUN TestProxyWriteTimeout/unknown_size810=== RUN TestIsValidUploadKey/build_log_question_mark811=== RUN TestIsValidCachePath/ls812=== PAUSE TestIsValidCachePath/ls813=== RUN TestIsValidCachePath/log814=== PAUSE TestIsValidCachePath/log815=== RUN TestIsValidCachePath/realisation816=== PAUSE TestIsValidCachePath/realisation817=== RUN TestIsValidCachePath/nix-cache-info818=== RUN TestParseSingleRange/suffix_exceeds_size819=== PAUSE TestParseSingleRange/suffix_exceeds_size820=== PAUSE TestProxyWriteTimeout/unknown_size821=== PAUSE TestIsValidUploadKey/build_log_question_mark822=== PAUSE TestIsValidCachePath/nix-cache-info823=== RUN TestIsValidCachePath/index.html824=== PAUSE TestIsValidCachePath/index.html825=== RUN TestIsValidCachePath/traversal_parent826=== PAUSE TestIsValidCachePath/traversal_parent827=== RUN TestIsValidCachePath/traversal_in_middle828=== RUN TestParseSingleRange/single_byte829=== PAUSE TestParseSingleRange/single_byte830=== RUN TestParseSingleRange/start_past_EOF831=== PAUSE TestParseSingleRange/start_past_EOF832=== RUN TestParseSingleRange/start_far_past_EOF833=== PAUSE TestParseSingleRange/start_far_past_EOF834=== CONT TestOrphanedObjectsGC835=== RUN TestIsValidUploadKey/build_log_equals836=== PAUSE TestIsValidUploadKey/build_log_equals837=== RUN TestIsValidUploadKey/realisation838=== PAUSE TestIsValidUploadKey/realisation839=== RUN TestIsValidUploadKey/realisation_plus_in_output840=== PAUSE TestIsValidUploadKey/realisation_plus_in_output841=== RUN TestIsValidUploadKey/nix-cache-info842=== PAUSE TestIsValidUploadKey/nix-cache-info843=== RUN TestIsValidUploadKey/index.html844=== PAUSE TestIsValidUploadKey/index.html845=== RUN TestIsValidUploadKey/narinfo_key,_nar_type846=== PAUSE TestIsValidCachePath/traversal_in_middle847=== CONT TestObjectStatsLargeCommit848=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type849=== RUN TestIsValidCachePath/invalid_char_e850=== RUN TestIsValidUploadKey/nar_key,_narinfo_type851=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type852=== RUN TestIsValidUploadKey/listing_key,_narinfo_type853=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type854=== RUN TestIsValidUploadKey/traversal855=== PAUSE TestIsValidUploadKey/traversal856=== RUN TestIsValidUploadKey/traversal_nar857=== PAUSE TestIsValidUploadKey/traversal_nar858=== RUN TestIsValidUploadKey/absolute859=== PAUSE TestIsValidUploadKey/absolute860=== RUN TestIsValidUploadKey/empty_key861=== PAUSE TestIsValidUploadKey/empty_key862=== RUN TestIsValidUploadKey/unknown_type863=== PAUSE TestIsValidUploadKey/unknown_type864=== PAUSE TestIsValidCachePath/invalid_char_e865=== CONT TestObjectStatsTrigger866=== RUN TestIsValidCachePath/invalid_char_u867=== PAUSE TestIsValidCachePath/invalid_char_u868=== RUN TestIsValidCachePath/random_path869=== PAUSE TestIsValidCachePath/random_path870=== RUN TestIsValidCachePath/empty871=== PAUSE TestIsValidCachePath/empty872=== RUN TestIsValidCachePath/leading_slash873=== PAUSE TestIsValidCachePath/leading_slash874=== RUN TestIsValidCachePath/wrong_extension875=== PAUSE TestIsValidCachePath/wrong_extension876=== RUN TestIsValidCachePath/short_hash877=== PAUSE TestIsValidCachePath/short_hash878=== CONT TestPendingCleanupUsesOneCutoff8792026/10/07 06:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39467/oidc880=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure881=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure882=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart883=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart884=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts885=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts886=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8872026/10/07 06:12:05 INFO Received push request method=POST path=/api/pushes8882026/10/07 06:12:05 INFO Received complete push request method=POST path=/api/pushes/1/complete8892026/10/07 06:12:05 INFO Received cleanup request method=DELETE path=/api/pending_closures8902026/10/07 06:12:05 INFO Aborted multipart uploads count=0 kept=08912026/10/07 06:12:05 INFO Completed push id=1 objects=4 duration=8.139238ms892--- PASS: TestPush_RepeatedRootCommitsOnce (0.48s)893=== CONT TestMultipartCleanup8942026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures8952026/10/07 06:12:05 INFO Received cleanup request method=DELETE path=/api/pending_closures8962026/10/07 06:12:05 INFO Aborted multipart uploads count=1 kept=08972026/10/07 06:12:05 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"898--- PASS: TestService_AuthMiddleware (0.50s)899=== CONT TestServerTLSConfig900=== RUN TestServerTLSConfig/no_client_CA901=== PAUSE TestServerTLSConfig/no_client_CA902=== RUN TestServerTLSConfig/missing_CA_file903=== PAUSE TestServerTLSConfig/missing_CA_file904=== RUN TestServerTLSConfig/not_a_PEM_file905=== PAUSE TestServerTLSConfig/not_a_PEM_file906=== CONT TestService_NativeMTLS9072026/10/07 06:12:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9082026-10-07 06:12:05.096 UTC [652] ERROR: Closure does not exist: id=19092026-10-07 06:12:05.096 UTC [652] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9102026-10-07 06:12:05.096 UTC [652] STATEMENT: -- name: CommitPendingClosure :one911 SELECT commit_pending_closure($1::bigint)::bigint912 913--- PASS: TestService_cleanupPendingClosuresHandler (0.50s)914=== CONT TestMetricsCommit9152026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures916--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)917=== CONT TestMetricsInventory9182026/10/07 06:12:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9192026/10/07 06:12:05 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst920--- PASS: TestCompleteMultipartUnregistered (0.56s)921=== CONT TestNARDeduplicationMetadataUploadBug9222026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures9232026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures9242026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures926--- PASS: TestReadProxyNarStreaming (0.67s)927=== CONT TestCreatePendingClosureRejectsOversizedNAR9282026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures929--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)930=== CONT TestCacheConfigHandlerMaxNarSize931--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)932=== CONT TestGenerateLandingPage933--- PASS: TestGenerateLandingPage (0.00s)934=== CONT TestService_readinessHandler935--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.70s)936=== CONT TestService_healthCheckHandler9372026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/07 06:12:05 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>939--- PASS: TestReadProxyNarinfo (0.73s)940=== CONT TestGracefulShutdownDrainsInflight9412026/10/07 06:12:05 INFO Starting HTTP server address=127.0.0.1:407859422026/10/07 06:12:05 INFO Shutdown signal received, draining in-flight requests timeout=10s9432026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures944--- PASS: TestPresentReportsOnlyClosureRoots (0.70s)945=== CONT TestGCTaskStore_Fail946--- PASS: TestGCTaskStore_Fail (0.00s)947=== CONT TestGCTaskStore_PhaseUpdates948--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)949=== CONT TestGCTaskStore_CompletedAllowsNewTask950--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)951=== CONT TestGCTaskStore_GetReturnsLatest952--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)953=== CONT TestGCTaskStore_GetEmpty954--- PASS: TestGCTaskStore_GetEmpty (0.00s)955=== CONT TestGCTaskStore_ConflictDifferentParams956--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)957=== CONT TestGCTaskStore_DeduplicateSameParams958--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)959=== CONT TestGCTaskStore_StartNew960--- PASS: TestGCTaskStore_StartNew (0.00s)961=== CONT TestGCEndsOnShutdown962=== RUN TestGCEndsOnShutdown/before_the_run963=== PAUSE TestGCEndsOnShutdown/before_the_run964=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete965=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete966=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark967=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark968=== CONT TestCommitRacingPendingCleanupKeepsObjects969--- PASS: TestGracefulShutdownDrainsInflight (0.07s)970=== CONT TestReadRedirectNar9712026/10/07 06:12:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9722026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures973--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.61s)974=== CONT TestResolveDBConnectionString975=== RUN TestResolveDBConnectionString/flag_wins976=== PAUSE TestResolveDBConnectionString/flag_wins977=== RUN TestResolveDBConnectionString/file_when_flag_empty978=== PAUSE TestResolveDBConnectionString/file_when_flag_empty979=== RUN TestResolveDBConnectionString/missing_file_is_an_error980=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error981=== RUN TestResolveDBConnectionString/PGHOST_allows_empty982=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty983=== RUN TestResolveDBConnectionString/nothing_configured984=== PAUSE TestResolveDBConnectionString/nothing_configured985=== CONT TestSweepRechecksPendingAfterLocking986--- PASS: TestReadProxy404 (0.79s)987=== CONT TestPush_CompleteCommitsEveryRoot9882026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures9892026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures9902026/10/07 06:12:05 INFO Received cleanup request method=DELETE path=/api/pending_closures991--- PASS: TestReadProxyContentNegotiation (0.85s)992=== CONT TestGetExistingObjectsLocksRows9932026/10/07 06:12:05 INFO Starting HTTP server address=127.0.0.1:399439942026/10/07 06:12:05 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3432317657/001/proxy.sock9952026/10/07 06:12:05 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9962026/10/07 06:12:05 INFO Shutdown signal received, draining in-flight requests timeout=10s997--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.88s)998=== CONT TestPush_OverlappingRootsStoreOneRowPerKey999--- PASS: TestPresentRefreshesOnlyStaleClosures (0.92s)1000=== CONT TestReadRedirectUsesPublicS3URL10012026/10/07 06:12:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10022026/10/07 06:12:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10032026/10/07 06:12:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LjYzNmM2NzI4LWUxYmUtNGY5Zi04OTI4LWM0YmEwZDRhOGI5N3gxNzkxMzUzNTI1MTg2NzA2NDU3 parts=1010042026/10/07 06:12:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10052026/10/07 06:12:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LjJkZDdmMmI1LTY5OWItNDUxOS1hNWZjLTZjNTc4NmMyYWY3OXgxNzkxMzUzNTI1MjE2Njk2NTQ5 parts=1010062026/10/07 06:12:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10072026/10/07 06:12:05 INFO Completed upload id=1 objects=2 duration=3.701289ms1008--- PASS: TestObjectStatsTrigger (1.00s)1009=== CONT TestReadProxyRangeRequest10102026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/07 06:12:05 INFO Completed upload id=1 objects=2 duration=5.161798ms10122026/10/07 06:12:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10132026/10/07 06:12:05 WARN Refused reserved pin name=worker-x86_64-linux10142026/10/07 06:12:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10152026/10/07 06:12:05 INFO Received create pin request method=POST path=/api/pins/my-app10162026/10/07 06:12:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10172026/10/07 06:12:05 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001018--- PASS: TestCreatePin_ReservedPins (1.01s)1019=== CONT TestRegisterCompletedObjectNeedsPendingRow10202026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures10212026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures10222026/10/07 06:12:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10232026/10/07 06:12:05 WARN Found objects in DB but missing from S3, will re-upload count=11024--- PASS: TestService_verifyS3Integrity (1.11s)1025=== CONT TestReadRedirectKeepsNarinfoProxied10262026/10/07 06:12:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures10272026/10/07 06:12:05 INFO Aborted multipart uploads count=0 kept=010282026/10/07 06:12:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10292026/10/07 06:12:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1030--- PASS: TestService_NativeMTLS (0.62s)1031=== CONT TestSweepSkipsRowsLockedByPush10322026/10/07 06:12:05 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=010332026/10/07 06:12:05 INFO Vacuumed table table=pending_closures10342026/10/07 06:12:05 INFO Vacuumed table table=pending_objects10352026/10/07 06:12:05 INFO Vacuumed table table=multipart_uploads10362026/10/07 06:12:05 INFO Vacuumed table table=closures10372026/10/07 06:12:05 INFO Vacuumed table table=objects10382026/10/07 06:12:05 INFO Received push request method=POST path=/api/pushes10392026/10/07 06:12:05 INFO Received uploads request method=POST path=/api/pending_closures10402026/10/07 06:12:05 INFO Received complete push request method=POST path=/api/pushes/1/complete10412026/10/07 06:12:05 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001042--- PASS: TestService_createPendingClosureHandler (1.21s)1043=== CONT TestFailedS3DeleteKeepsTombstone10442026/10/07 06:12:05 INFO Completed push id=1 objects=4 duration=11.080777ms10452026/10/07 06:12:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10462026/10/07 06:12:05 INFO Completed upload id=2 objects=2 duration=1.42621ms1047--- PASS: TestMetricsCommit (0.73s)1048=== CONT TestForceGCDuringPushOffersSweptObject1049=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1050=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1051=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1052=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1053=== CONT TestReadProxyConditionalGet1054--- PASS: TestMetricsInventory (0.69s)1055=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10562026/10/07 06:12:05 WARN readiness check failed error="closed pool"1057--- PASS: TestService_readinessHandler (0.59s)1058=== CONT TestGCSweepDeliversEachKeyOnce1059--- PASS: TestPushWaitsForSweepHoldingRow (1.29s)1060=== CONT TestReadProxyDisabled1061=== NAME TestNARDeduplicationMetadataUploadBug1062 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1364869850/001/store/5qllc805cc4v4f9h2rks5c8jg196l1sm-file1.txt1063--- PASS: TestService_healthCheckHandler (0.59s)1064=== CONT TestTombstonedObjectOfferedWithoutWaiting10652026/10/07 06:12:05 INFO Received cleanup request method=DELETE path=/api/pending_closures10662026/10/07 06:12:05 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket29/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10672026/10/07 06:12:05 INFO Aborted multipart uploads count=0 kept=110682026/10/07 06:12:05 INFO Received cleanup request method=DELETE path=/api/pending_closures10692026/10/07 06:12:05 INFO Aborted multipart uploads count=1 kept=01070--- PASS: TestReadRedirectNar (0.55s)1071=== CONT TestReadProxyRootRedirectsToIndexHTML1072--- PASS: TestMultipartCleanup (0.88s)1073=== CONT TestGCSweepSkipsPendingObjects10742026/10/07 06:12:05 INFO Received push request method=POST path=/api/pushes10752026/10/07 06:12:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10762026/10/07 06:12:05 INFO Uploading 5qllc805cc4v4f9h2rks5c8jg196l1sm-file1.txt (160B)10772026/10/07 06:12:05 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10782026/10/07 06:12:05 WARN Failed to register uploaded object key=5qllc805cc4v4f9h2rks5c8jg196l1sm.ls error="server returned 404: 404 page not found\n"10792026/10/07 06:12:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10802026/10/07 06:12:05 INFO Signed narinfos id=1 count=110812026/10/07 06:12:05 INFO Uploading 1 narinfos10822026/10/07 06:12:05 INFO Received complete push request method=POST path=/api/pushes/1/complete10832026/10/07 06:12:05 WARN Failed to register uploaded object key=5qllc805cc4v4f9h2rks5c8jg196l1sm.narinfo error="server returned 404: 404 page not found\n"10842026/10/07 06:12:05 INFO Aborted multipart uploads count=0 kept=010852026/10/07 06:12:05 WARN Force mode enabled - objects will be deleted immediately without grace period10862026/10/07 06:12:05 INFO Aborted multipart uploads count=0 kept=010872026/10/07 06:12:05 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=010882026/10/07 06:12:05 INFO Completed push id=1 objects=3 duration=10.372717ms10892026/10/07 06:12:05 INFO Upload complete. (73ms)1090=== NAME TestNARDeduplicationMetadataUploadBug1091 metadata_upload_test.go:54: Retrieved narinfo from S3:1092 StorePath: /build/TestNARDeduplicationMetadataUploadBug1364869850/001/store/5qllc805cc4v4f9h2rks5c8jg196l1sm-file1.txt1093 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1094 Compression: zstd1095 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1096 NarSize: 1601097 References: 1098 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10992026/10/07 06:12:06 INFO Vacuumed table table=pending_closures1100 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)11012026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period1102 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1103 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11042026/10/07 06:12:06 INFO Received push request method=POST path=/api/pushes11052026/10/07 06:12:06 INFO Vacuumed table table=pending_objects11062026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads11072026/10/07 06:12:06 INFO Vacuumed table table=closures11082026/10/07 06:12:06 INFO Vacuumed table table=objects1109--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.63s)1110=== CONT TestDeduplicatedObjectsRecordedAsPending11112026/10/07 06:12:06 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=011122026/10/07 06:12:06 INFO Vacuumed table table=pending_closures11132026/10/07 06:12:06 INFO Vacuumed table table=pending_objects11142026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads11152026/10/07 06:12:06 INFO Vacuumed table table=closures1116=== NAME TestOrphanedObjectsGC1117 orphaned_objects_gc_test.go:287: GC Test Summary:1118 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1119 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1120 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1121 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1122 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1123--- PASS: TestOrphanedObjectsGC (1.34s)1124=== CONT TestPushDedupSurvivesConcurrentGC11252026/10/07 06:12:06 INFO Received complete push request method=POST path=/api/pushes/1/complete11262026/10/07 06:12:06 INFO Vacuumed table table=objects1127--- PASS: TestSweepRechecksPendingAfterLocking (0.58s)1128=== CONT TestClientErrorHandling1129=== RUN TestClientErrorHandling/InvalidStorePath1130=== PAUSE TestClientErrorHandling/InvalidStorePath1131=== RUN TestClientErrorHandling/InvalidAuthToken1132=== PAUSE TestClientErrorHandling/InvalidAuthToken1133=== RUN TestClientErrorHandling/ServerNotAvailable1134=== PAUSE TestClientErrorHandling/ServerNotAvailable1135=== CONT TestGCMetrics1136=== NAME TestNARDeduplicationMetadataUploadBug1137 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1364869850/001/store/k8kf2i7p4j42x4ycapqs7s7rj64viz7n-file2.txt11382026/10/07 06:12:06 INFO Completed push id=1 objects=6 duration=19.914984ms1139--- PASS: TestPush_CompleteCommitsEveryRoot (0.57s)1140=== CONT TestGCBugBareHashReferences11412026/10/07 06:12:06 INFO Received push request method=POST path=/api/pushes1142--- PASS: TestGetExistingObjectsLocksRows (0.53s)1143=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1144--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.53s)1145=== CONT TestGCAdvisoryLockBlocksConcurrentRun1146--- PASS: TestReadRedirectUsesPublicS3URL (0.49s)1147=== CONT TestDeleteClosuresRacingPins11482026/10/07 06:12:06 INFO Received push request method=POST path=/api/pushes11492026/10/07 06:12:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11502026/10/07 06:12:06 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11512026/10/07 06:12:06 WARN Failed to register uploaded object key=k8kf2i7p4j42x4ycapqs7s7rj64viz7n.ls error="server returned 404: 404 page not found\n"11522026/10/07 06:12:06 INFO Signed narinfos id=2 count=111532026/10/07 06:12:06 INFO Uploading 1 narinfos1154--- PASS: TestReadProxyRangeRequest (0.43s)1155=== CONT TestLeadEndsOnShutdown11562026/10/07 06:12:06 INFO Received complete push request method=POST path=/api/pushes/2/complete11572026/10/07 06:12:06 WARN Failed to register uploaded object key=k8kf2i7p4j42x4ycapqs7s7rj64viz7n.narinfo error="server returned 404: 404 page not found\n"11582026/10/07 06:12:06 INFO Completed push id=2 objects=3 duration=3.438759ms11592026/10/07 06:12:06 INFO Upload complete. (57ms)1160=== NAME TestNARDeduplicationMetadataUploadBug1161 metadata_upload_test.go:76: Retrieved narinfo from S3:1162 StorePath: /build/TestNARDeduplicationMetadataUploadBug1364869850/001/store/k8kf2i7p4j42x4ycapqs7s7rj64viz7n-file2.txt1163 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1164 Compression: zstd1165 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1166 NarSize: 1601167 References: 1168 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1169 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1170 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1171 {"version":1,"root":{"type":"regular","size":44}}1172--- PASS: TestNARDeduplicationMetadataUploadBug (0.99s)1173=== CONT TestClientFallsBackToClosures1174--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.49s)1175=== CONT TestLeadIncumbentAnnouncesAtOnce1176--- PASS: TestReadRedirectKeepsNarinfoProxied (0.50s)1177=== CONT TestClientPushesUseOnePush11782026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures11792026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=011802026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period11812026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures11822026/10/07 06:12:06 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=011832026/10/07 06:12:06 INFO Vacuumed table table=pending_closures11842026/10/07 06:12:06 INFO Vacuumed table table=pending_objects11852026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads11862026/10/07 06:12:06 INFO Vacuumed table table=closures11872026/10/07 06:12:06 INFO Vacuumed table table=objects11882026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=011892026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period11902026/10/07 06:12:06 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=011912026/10/07 06:12:06 INFO Vacuumed table table=pending_closures11922026/10/07 06:12:06 INFO Vacuumed table table=pending_objects11932026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads11942026/10/07 06:12:06 INFO Vacuumed table table=closures11952026/10/07 06:12:06 INFO Vacuumed table table=objects1196--- PASS: TestSweepSkipsRowsLockedByPush (0.58s)1197=== CONT TestLeadElectsOneAndHandsOver1198--- PASS: TestReadProxyConditionalGet (0.49s)1199=== CONT TestPinProtectsFromGC1200--- PASS: TestReadProxyDisabled (0.46s)1201=== CONT TestConnectWaitsForAPeerMigration12022026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=012032026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period12042026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures12052026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=012062026/10/07 06:12:06 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12072026/10/07 06:12:06 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12082026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period1209--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.49s)1210=== CONT TestClientSharedPathCommittedMidPush1211--- PASS: TestFailedS3DeleteKeepsTombstone (0.58s)1212=== CONT TestClientMultipleUploads12132026/10/07 06:12:06 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=01214--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.44s)1215=== CONT TestClientIntegration12162026/10/07 06:12:06 INFO Vacuumed table table=pending_closures12172026/10/07 06:12:06 INFO Vacuumed table table=pending_objects12182026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads12192026/10/07 06:12:06 INFO Vacuumed table table=closures12202026/10/07 06:12:06 INFO Vacuumed table table=objects1221--- PASS: TestGCSweepDeliversEachKeyOnce (0.54s)1222=== CONT TestClientWithDependencies12232026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures12242026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures1225--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.44s)1226=== CONT TestService_RequireScope_OIDC12272026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=01228--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.63s)1229=== CONT TestService_ReadAuthMiddleware12302026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period12312026/10/07 06:12:06 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=01232--- PASS: TestObjectStatsLargeCommit (1.80s)1233=== CONT TestClientCADerivations12342026/10/07 06:12:06 INFO Vacuumed table table=pending_closures12352026/10/07 06:12:06 INFO Vacuumed table table=pending_objects12362026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads12372026/10/07 06:12:06 INFO Vacuumed table table=closures12382026/10/07 06:12:06 INFO Vacuumed table table=objects12392026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=01240--- PASS: TestGCSweepSkipsPendingObjects (0.55s)1241=== CONT TestService_AuthMiddleware_OIDC12422026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period12442026/10/07 06:12:06 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=012452026/10/07 06:12:06 INFO Vacuumed table table=pending_closures12462026/10/07 06:12:06 INFO Vacuumed table table=pending_objects12472026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads12482026/10/07 06:12:06 INFO Vacuumed table table=closures12492026/10/07 06:12:06 INFO Vacuumed table table=objects1250--- PASS: TestGCMetrics (0.49s)1251=== CONT TestCacheStatsHandler12522026/10/07 06:12:06 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1253--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.49s)1254=== CONT TestCacheConfigHandler1255=== RUN TestCacheConfigHandler/full_config,_no_issuer1256=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1257=== RUN TestCacheConfigHandler/no_cache_url_configured1258=== PAUSE TestCacheConfigHandler/no_cache_url_configured1259=== RUN TestCacheConfigHandler/no_signing_keys1260=== PAUSE TestCacheConfigHandler/no_signing_keys1261=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1262=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1263=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12642026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=012652026/10/07 06:12:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44925/oidc12662026/10/07 06:12:06 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=012672026/10/07 06:12:06 INFO Vacuumed table table=pending_closures12682026/10/07 06:12:06 INFO Vacuumed table table=pending_objects12692026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads12702026/10/07 06:12:06 INFO Vacuumed table table=closures12712026/10/07 06:12:06 INFO Vacuumed table table=objects12722026/10/07 06:12:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45069/oidc12732026/10/07 06:12:06 INFO Aborted multipart uploads count=0 kept=012742026/10/07 06:12:06 WARN Force mode enabled - objects will be deleted immediately without grace period12752026/10/07 06:12:06 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=012762026/10/07 06:12:06 INFO Vacuumed table table=pending_closures12772026/10/07 06:12:06 INFO Vacuumed table table=pending_objects12782026/10/07 06:12:06 INFO Vacuumed table table=multipart_uploads12792026/10/07 06:12:06 INFO Vacuumed table table=closures12802026/10/07 06:12:06 INFO Vacuumed table table=objects1281--- PASS: TestPushDedupSurvivesConcurrentGC (0.61s)1282=== CONT TestService_ReadScope_PublicByDefault12832026/10/07 06:12:06 INFO lead: acquired remote=192.0.2.1:123412842026/10/07 06:12:06 INFO lead: acquired remote=192.0.2.1:123412852026/10/07 06:12:06 INFO lead: released remote=192.0.2.1:12341286--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.48s)1287=== CONT TestRedundantMultipartUpload12882026/10/07 06:12:06 INFO lead: acquired remote=192.0.2.1:12341289--- PASS: TestGCBugBareHashReferences (0.75s)1290=== CONT TestReadProxyHead1291--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.74s)1292=== CONT TestParseSize1293--- PASS: TestParseSize (0.00s)1294=== CONT TestReadProxyOutlastsServerWriteTimeout1295=== NAME TestClientIntegration1296 client_integration_test.go:286: Created store path: /build/TestClientIntegration2849685914/002/store/yihqazk6zkw6nhgbh50l0y7nh4lida7r-test-file.txt1297=== NAME TestPinProtectsFromGC1298 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2667362631/001/store/6i1zs7jmsab63mis6vf39xdqqa2h2bj0-pinned-file.txt1299 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2667362631/001/store/ab3hcvcxhwrhxjl18h2af1a996n7yw84-unpinned-file.txt13002026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures13012026/10/07 06:12:06 INFO Received uploads request method=POST path=/api/pending_closures13022026/10/07 06:12:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13032026/10/07 06:12:06 INFO Uploading kqnvfs6spvjngkkfffbz7g8nqwa1vva6-shared-dep (136B)13042026/10/07 06:12:06 INFO Uploading q5634kjqk59x1as9c4a4ljq2j3wqbmcr-b (216B)13052026/10/07 06:12:06 WARN Failed to register uploaded object key=msxnfnjz4s07id930h6675b3s3h1anci.ls error="server returned 404: 404 page not found\n"13062026/10/07 06:12:06 WARN Failed to register uploaded object key=kqnvfs6spvjngkkfffbz7g8nqwa1vva6.ls error="server returned 404: 404 page not found\n"13072026/10/07 06:12:06 WARN Failed to register uploaded object key=q5634kjqk59x1as9c4a4ljq2j3wqbmcr.ls error="server returned 404: 404 page not found\n"13082026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13092026/10/07 06:12:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13102026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/0vbjw5sqws7bdgnh6ap98d5wh3gl52qfqh9xd253ph76fp6900hx.nar.zst error="server returned 404: 404 page not found\n"13112026/10/07 06:12:06 INFO Signed narinfos id=1 count=213122026/10/07 06:12:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13132026/10/07 06:12:06 INFO Signed narinfos id=2 count=213142026/10/07 06:12:06 INFO Uploading 4 narinfos13152026/10/07 06:12:06 WARN Failed to register uploaded object key=kqnvfs6spvjngkkfffbz7g8nqwa1vva6.narinfo error="server returned 404: 404 page not found\n"13162026/10/07 06:12:06 WARN Failed to register uploaded object key=msxnfnjz4s07id930h6675b3s3h1anci.narinfo error="server returned 404: 404 page not found\n"13172026/10/07 06:12:06 WARN Failed to register uploaded object key=kqnvfs6spvjngkkfffbz7g8nqwa1vva6.narinfo error="server returned 404: 404 page not found\n"13182026/10/07 06:12:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13192026/10/07 06:12:06 WARN Failed to register uploaded object key=q5634kjqk59x1as9c4a4ljq2j3wqbmcr.narinfo error="server returned 404: 404 page not found\n"1320--- PASS: TestService_ReadAuthMiddleware (0.40s)1321=== CONT TestService_Rustfstest1322=== NAME TestClientMultipleUploads1323 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4266012560/001/store/zyjbcj6qq9isvg1ibiqr93gwwxfbcygp-test-file-0.txt13242026/10/07 06:12:06 INFO Completed upload id=1 objects=6 duration=9.436257ms13252026/10/07 06:12:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13262026/10/07 06:12:06 INFO Completed upload id=2 objects=6 duration=2.930209ms13272026/10/07 06:12:06 INFO Upload complete. (99ms)1328=== NAME TestClientFallsBackToClosures1329 client_pushes_test.go:112: Retrieved narinfo from S3:1330 StorePath: /build/TestClientFallsBackToClosures3148797378/001/store/kqnvfs6spvjngkkfffbz7g8nqwa1vva6-shared-dep1331 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1332 Compression: zstd1333 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821334 NarSize: 1361335 References: 1336 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1337 client_pushes_test.go:112: Retrieved narinfo from S3:1338 StorePath: /build/TestClientFallsBackToClosures3148797378/001/store/msxnfnjz4s07id930h6675b3s3h1anci-a1339 URL: nar/0vbjw5sqws7bdgnh6ap98d5wh3gl52qfqh9xd253ph76fp6900hx.nar.zst1340 Compression: zstd1341 NarHash: sha256:0vbjw5sqws7bdgnh6ap98d5wh3gl52qfqh9xd253ph76fp6900hx1342 NarSize: 2161343 References: /build/TestClientFallsBackToClosures3148797378/001/store/kqnvfs6spvjngkkfffbz7g8nqwa1vva6-shared-dep1344 CA: text:sha256:0dqyv939fsxyqx4p15fbizrqgnsg41flz8h8nv7x6baa8caf5q7d1345 client_pushes_test.go:112: Retrieved narinfo from S3:1346 StorePath: /build/TestClientFallsBackToClosures3148797378/001/store/q5634kjqk59x1as9c4a4ljq2j3wqbmcr-b1347 URL: nar/0vbjw5sqws7bdgnh6ap98d5wh3gl52qfqh9xd253ph76fp6900hx.nar.zst1348 Compression: zstd1349 NarHash: sha256:0vbjw5sqws7bdgnh6ap98d5wh3gl52qfqh9xd253ph76fp6900hx1350 NarSize: 2161351 References: /build/TestClientFallsBackToClosures3148797378/001/store/kqnvfs6spvjngkkfffbz7g8nqwa1vva6-shared-dep1352 CA: text:sha256:0dqyv939fsxyqx4p15fbizrqgnsg41flz8h8nv7x6baa8caf5q7d1353--- PASS: TestClientFallsBackToClosures (0.75s)1354=== CONT TestPush_RootsAreLockedInByteOrder13552026/10/07 06:12:06 INFO Received push request method=POST path=/api/pushes13562026/10/07 06:12:06 INFO Received push request method=POST path=/api/pushes13572026/10/07 06:12:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13582026/10/07 06:12:06 INFO Uploading yihqazk6zkw6nhgbh50l0y7nh4lida7r-test-file.txt (152B)13592026/10/07 06:12:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13602026/10/07 06:12:06 INFO Uploading h187ixn6sh1izjzn7avxh4hx456j0gvr-shared-dep (136B)13612026/10/07 06:12:06 INFO Uploading c8p4c8s2jf23i47gnchqmpj1jqzy1236-a (208B)13622026/10/07 06:12:06 INFO Received push request method=POST path=/api/pushes13632026/10/07 06:12:06 WARN Failed to register uploaded object key=fzbnliqn77j03a3jhsad2jvx2zbv529w.ls error="server returned 404: 404 page not found\n"13642026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13652026/10/07 06:12:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13662026/10/07 06:12:06 WARN Failed to register uploaded object key=yihqazk6zkw6nhgbh50l0y7nh4lida7r.ls error="server returned 404: 404 page not found\n"13672026/10/07 06:12:06 INFO Signed narinfos id=1 count=11368=== NAME TestClientMultipleUploads13692026/10/07 06:12:06 INFO Uploading 1 narinfos1370 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4266012560/001/store/188nc17k0wrydskd8fyf47ch3nyh0r55-test-file-1.txt13712026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13722026/10/07 06:12:06 WARN Failed to register uploaded object key=c8p4c8s2jf23i47gnchqmpj1jqzy1236.ls error="server returned 404: 404 page not found\n"13732026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/0qxi03ljqdr4c8cr4pbfp1s2va99yycymsb3agids535lbsd1hdy.nar.zst error="server returned 404: 404 page not found\n"13742026/10/07 06:12:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13752026/10/07 06:12:06 INFO Uploading 6i1zs7jmsab63mis6vf39xdqqa2h2bj0-pinned-file.txt (128B)13762026/10/07 06:12:06 WARN Failed to register uploaded object key=h187ixn6sh1izjzn7avxh4hx456j0gvr.ls error="server returned 404: 404 page not found\n"13772026/10/07 06:12:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13782026/10/07 06:12:06 INFO Signed narinfos id=1 count=313792026/10/07 06:12:06 INFO Uploading 3 narinfos13802026/10/07 06:12:06 INFO Received complete push request method=POST path=/api/pushes/1/complete13812026/10/07 06:12:06 WARN Failed to register uploaded object key=yihqazk6zkw6nhgbh50l0y7nh4lida7r.narinfo error="server returned 404: 404 page not found\n"13822026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13832026/10/07 06:12:06 WARN Failed to register uploaded object key=6i1zs7jmsab63mis6vf39xdqqa2h2bj0.ls error="server returned 404: 404 page not found\n"13842026/10/07 06:12:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13852026/10/07 06:12:06 WARN Failed to register uploaded object key=c8p4c8s2jf23i47gnchqmpj1jqzy1236.narinfo error="server returned 404: 404 page not found\n"13862026/10/07 06:12:06 WARN Failed to register uploaded object key=fzbnliqn77j03a3jhsad2jvx2zbv529w.narinfo error="server returned 404: 404 page not found\n"13872026/10/07 06:12:06 INFO Signed narinfos id=1 count=113882026/10/07 06:12:06 INFO Received complete push request method=POST path=/api/pushes/1/complete13892026/10/07 06:12:06 WARN Failed to register uploaded object key=h187ixn6sh1izjzn7avxh4hx456j0gvr.narinfo error="server returned 404: 404 page not found\n"13902026/10/07 06:12:06 INFO Uploading 1 narinfos13912026/10/07 06:12:06 INFO Received complete push request method=POST path=/api/pushes/1/complete13922026/10/07 06:12:06 WARN Failed to register uploaded object key=6i1zs7jmsab63mis6vf39xdqqa2h2bj0.narinfo error="server returned 404: 404 page not found\n"13932026/10/07 06:12:06 INFO Completed push id=1 objects=3 duration=8.138368ms13942026/10/07 06:12:06 INFO Upload complete. (73ms)1395=== NAME TestClientWithDependencies1396 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1371530542/001/store/01dh0qadhsivmfs29jankrqbx7g9kdg9-test-script13972026/10/07 06:12:06 INFO Completed push id=1 objects=8 duration=11.035687ms13982026/10/07 06:12:06 INFO Upload complete. (84ms)1399=== NAME TestClientPushesUseOnePush14002026/10/07 06:12:06 INFO Completed push id=1 objects=3 duration=8.110398ms1401 client_pushes_test.go:97: Retrieved narinfo from S3:1402 StorePath: /build/TestClientPushesUseOnePush596077345/001/store/h187ixn6sh1izjzn7avxh4hx456j0gvr-shared-dep1403 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst14042026/10/07 06:12:06 INFO Upload complete. (67ms)1405 Compression: zstd1406 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821407 NarSize: 1361408 References: 1409 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1410 client_pushes_test.go:97: Retrieved narinfo from S3:1411 StorePath: /build/TestClientPushesUseOnePush596077345/001/store/c8p4c8s2jf23i47gnchqmpj1jqzy1236-a1412 URL: nar/0qxi03ljqdr4c8cr4pbfp1s2va99yycymsb3agids535lbsd1hdy.nar.zst1413 Compression: zstd1414 NarHash: sha256:0qxi03ljqdr4c8cr4pbfp1s2va99yycymsb3agids535lbsd1hdy1415 NarSize: 2081416 References: /build/TestClientPushesUseOnePush596077345/001/store/h187ixn6sh1izjzn7avxh4hx456j0gvr-shared-dep1417 CA: text:sha256:0vqx2i3d5lkfqara2fr5j6zw0xiah65zwsb1ylvmla3y6xwsxhly1418--- PASS: TestCacheStatsHandler (0.41s)1419=== CONT TestReadProxyInvalidPath1420=== NAME TestClientPushesUseOnePush1421 client_pushes_test.go:97: Retrieved narinfo from S3:1422 StorePath: /build/TestClientPushesUseOnePush596077345/001/store/fzbnliqn77j03a3jhsad2jvx2zbv529w-b1423 URL: nar/0qxi03ljqdr4c8cr4pbfp1s2va99yycymsb3agids535lbsd1hdy.nar.zst1424 Compression: zstd1425 NarHash: sha256:0qxi03ljqdr4c8cr4pbfp1s2va99yycymsb3agids535lbsd1hdy1426 NarSize: 2081427 References: /build/TestClientPushesUseOnePush596077345/001/store/h187ixn6sh1izjzn7avxh4hx456j0gvr-shared-dep1428 CA: text:sha256:0vqx2i3d5lkfqara2fr5j6zw0xiah65zwsb1ylvmla3y6xwsxhly14292026/10/07 06:12:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14302026/10/07 06:12:06 WARN mTLS auth: bound subjects configured but subject DN unavailable1431--- PASS: TestClientPushesUseOnePush (0.74s)14322026/10/07 06:12:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1433=== CONT TestPush_CompleteWaitsForCleanupOfThePush1434--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)1435=== CONT TestPresignedUploadRegisteredBeforeCommit1436=== NAME TestClientMultipleUploads1437 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4266012560/001/store/fkpynj3kmiwshs6mvf161pm13r6g6ygi-test-file-2.txt14382026/10/07 06:12:06 INFO Received push request method=POST path=/api/pushes14392026/10/07 06:12:06 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14402026/10/07 06:12:06 INFO Uploading f24r3r3fqg0xq7p6g9dyg37pbqjbniqj-top (224B)14412026/10/07 06:12:06 INFO Uploading 48yi29ws93vnm36pclvdnwbnib0mpq04-shared-dep (136B)1442=== NAME TestClientWithDependencies1443 client_integration_test.go:615: Found 1 dependencies (including self)14442026/10/07 06:12:06 INFO All 1 paths already cached14452026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/0xcwgvhxqnkq9ikac7myql3vb2rlpxjh1m4y0sld5mc3yidh988v.nar.zst error="server returned 404: 404 page not found\n"14462026/10/07 06:12:06 WARN Failed to register uploaded object key=48yi29ws93vnm36pclvdnwbnib0mpq04.ls error="server returned 404: 404 page not found\n"1447=== NAME TestClientIntegration1448 client_integration_test.go:312: Retrieved narinfo from S3:1449 StorePath: /build/TestClientIntegration2849685914/002/store/yihqazk6zkw6nhgbh50l0y7nh4lida7r-test-file.txt1450 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1451 Compression: zstd14522026/10/07 06:12:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1453 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11454 NarSize: 1521455 References: 1456 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk114572026/10/07 06:12:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14582026/10/07 06:12:06 WARN Failed to register uploaded object key=f24r3r3fqg0xq7p6g9dyg37pbqjbniqj.ls error="server returned 404: 404 page not found\n"14592026/10/07 06:12:06 INFO Signed narinfos id=1 count=214602026/10/07 06:12:06 INFO Uploading 2 narinfos1461 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1462 client_integration_test.go:313: Decompressed .ls content (64 bytes):1463 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1464 client_integration_test.go:316: Testing garbage collection...14652026/10/07 06:12:06 WARN Failed to register uploaded object key=f24r3r3fqg0xq7p6g9dyg37pbqjbniqj.narinfo error="server returned 404: 404 page not found\n"14662026/10/07 06:12:06 INFO Received complete push request method=POST path=/api/pushes/1/complete14672026/10/07 06:12:06 WARN Failed to register uploaded object key=48yi29ws93vnm36pclvdnwbnib0mpq04.narinfo error="server returned 404: 404 page not found\n"1468=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1469=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1470=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1471=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1472=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1473=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1474=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1475=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1476=== CONT TestCompletedNarNotReofferedAcrossClosures14772026/10/07 06:12:06 INFO Completed push id=1 objects=6 duration=11.946666ms14782026/10/07 06:12:06 INFO Upload complete. (68ms)1479=== NAME TestClientSharedPathCommittedMidPush1480 client_integration_test.go:680: Retrieved narinfo from S3:1481 StorePath: /build/TestClientSharedPathCommittedMidPush3800520264/001/store/48yi29ws93vnm36pclvdnwbnib0mpq04-shared-dep1482 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1483 Compression: zstd1484 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821485 NarSize: 1361486 References: 1487 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1488 client_integration_test.go:680: Retrieved narinfo from S3:1489 StorePath: /build/TestClientSharedPathCommittedMidPush3800520264/001/store/f24r3r3fqg0xq7p6g9dyg37pbqjbniqj-top1490 URL: nar/0xcwgvhxqnkq9ikac7myql3vb2rlpxjh1m4y0sld5mc3yidh988v.nar.zst1491 Compression: zstd1492 NarHash: sha256:0xcwgvhxqnkq9ikac7myql3vb2rlpxjh1m4y0sld5mc3yidh988v1493 NarSize: 2241494 References: /build/TestClientSharedPathCommittedMidPush3800520264/001/store/48yi29ws93vnm36pclvdnwbnib0mpq04-shared-dep1495 CA: text:sha256:04h59nx8nnr9nv90h7p43bn6zg624lqj57inaaz95c1rxlr5rsll1496=== NAME TestClientCADerivations1497 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations626319252/001/store/zvnrjm3x7fhxvfvnj14m2l3393nfaam0-ca-test1498--- PASS: TestClientSharedPathCommittedMidPush (0.61s)1499=== CONT TestService_AuthMiddleware_MTLSProxyHeader15002026/10/07 06:12:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures15012026/10/07 06:12:07 INFO Garbage collection started15022026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes1503=== RUN TestService_RequireScope_OIDC/builder_may_write1504=== PAUSE TestService_RequireScope_OIDC/builder_may_write1505=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1506=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1507=== RUN TestService_RequireScope_OIDC/ops_may_admin1508=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1509=== RUN TestService_RequireScope_OIDC/ops_may_not_write1510=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1511=== RUN TestService_RequireScope_OIDC/reader_may_not_write1512=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1513=== RUN TestService_RequireScope_OIDC/static_token_may_admin1514=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1515=== RUN TestService_RequireScope_OIDC/static_token_may_write1516=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1517=== RUN TestService_RequireScope_OIDC/reader_may_read1518=== PAUSE TestService_RequireScope_OIDC/reader_may_read1519=== RUN TestService_RequireScope_OIDC/writer_implies_read1520=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1521=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1522=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1523=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1524=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1525=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1526=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1527=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1528=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1529=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1530=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1531=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15322026/10/07 06:12:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15332026/10/07 06:12:07 INFO Uploading ab3hcvcxhwrhxjl18h2af1a996n7yw84-unpinned-file.txt (128B)15342026/10/07 06:12:07 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15352026/10/07 06:12:07 WARN Failed to register uploaded object key=ab3hcvcxhwrhxjl18h2af1a996n7yw84.ls error="server returned 404: 404 page not found\n"15362026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15372026/10/07 06:12:07 INFO Signed narinfos id=2 count=115382026/10/07 06:12:07 INFO Uploading 1 narinfos1539=== NAME TestClientCADerivations1540 client_ca_test.go:139: Found 1 dependencies (including self)15412026/10/07 06:12:07 INFO Aborted multipart uploads count=0 kept=015422026/10/07 06:12:07 INFO Received complete push request method=POST path=/api/pushes/2/complete15432026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures15442026/10/07 06:12:07 WARN Failed to register uploaded object key=ab3hcvcxhwrhxjl18h2af1a996n7yw84.narinfo error="server returned 404: 404 page not found\n"15452026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes15462026/10/07 06:12:07 INFO Completed push id=2 objects=3 duration=3.201239ms15472026/10/07 06:12:07 INFO Upload complete. (65ms)15482026/10/07 06:12:07 WARN Force mode enabled - objects will be deleted immediately without grace period15492026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes15502026/10/07 06:12:07 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15512026/10/07 06:12:07 INFO Uploading 188nc17k0wrydskd8fyf47ch3nyh0r55-test-file-1.txt (160B)15522026/10/07 06:12:07 INFO Uploading fkpynj3kmiwshs6mvf161pm13r6g6ygi-test-file-2.txt (160B)15532026/10/07 06:12:07 INFO Uploading zyjbcj6qq9isvg1ibiqr93gwwxfbcygp-test-file-0.txt (160B)15542026/10/07 06:12:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15552026/10/07 06:12:07 INFO Uploading 01dh0qadhsivmfs29jankrqbx7g9kdg9-test-script (136B)15562026/10/07 06:12:07 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15572026/10/07 06:12:07 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15582026/10/07 06:12:07 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15592026/10/07 06:12:07 WARN Failed to register uploaded object key=188nc17k0wrydskd8fyf47ch3nyh0r55.ls error="server returned 404: 404 page not found\n"15602026/10/07 06:12:07 WARN Failed to register uploaded object key=zyjbcj6qq9isvg1ibiqr93gwwxfbcygp.ls error="server returned 404: 404 page not found\n"15612026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures15622026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15632026/10/07 06:12:07 WARN Failed to register uploaded object key=fkpynj3kmiwshs6mvf161pm13r6g6ygi.ls error="server returned 404: 404 page not found\n"15642026/10/07 06:12:07 INFO Signed narinfos id=1 count=315652026/10/07 06:12:07 INFO Uploading 3 narinfos15662026/10/07 06:12:07 WARN Failed to register uploaded object key=01dh0qadhsivmfs29jankrqbx7g9kdg9.ls error="server returned 404: 404 page not found\n"15672026/10/07 06:12:07 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15682026/10/07 06:12:07 WARN Failed to register uploaded object key=log/lvfwg57yl5vkn76mzrsx8d7dnmhn7qvw-test-script.drv error="server returned 404: 404 page not found\n"15692026/10/07 06:12:07 WARN Failed to register uploaded object key=zyjbcj6qq9isvg1ibiqr93gwwxfbcygp.narinfo error="server returned 404: 404 page not found\n"15702026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15712026/10/07 06:12:07 WARN Failed to register uploaded object key=fkpynj3kmiwshs6mvf161pm13r6g6ygi.narinfo error="server returned 404: 404 page not found\n"15722026/10/07 06:12:07 INFO Signed narinfos id=1 count=115732026/10/07 06:12:07 INFO Received complete push request method=POST path=/api/pushes/1/complete15742026/10/07 06:12:07 WARN Failed to register uploaded object key=188nc17k0wrydskd8fyf47ch3nyh0r55.narinfo error="server returned 404: 404 page not found\n"15752026/10/07 06:12:07 INFO Uploading 1 narinfos15762026/10/07 06:12:07 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=015772026/10/07 06:12:07 INFO Received complete push request method=POST path=/api/pushes/1/complete15782026/10/07 06:12:07 WARN Failed to register uploaded object key=01dh0qadhsivmfs29jankrqbx7g9kdg9.narinfo error="server returned 404: 404 page not found\n"15792026/10/07 06:12:07 INFO Vacuumed table table=pending_closures1580--- PASS: TestService_ReadScope_PublicByDefault (0.42s)1581=== CONT TestPush_SignsNarinfosOfItsPendingObjects15822026/10/07 06:12:07 INFO Vacuumed table table=pending_objects15832026/10/07 06:12:07 INFO Vacuumed table table=multipart_uploads15842026/10/07 06:12:07 INFO Completed push id=1 objects=9 duration=11.151287ms15852026/10/07 06:12:07 INFO Upload complete. (77ms)1586=== NAME TestClientMultipleUploads1587 client_integration_test.go:369: Uploaded 3 paths in 112.228379ms15882026/10/07 06:12:07 INFO Vacuumed table table=closures15892026/10/07 06:12:07 INFO Completed push id=1 objects=4 duration=11.024956ms15902026/10/07 06:12:07 INFO Upload complete. (72ms)15912026/10/07 06:12:07 INFO Vacuumed table table=objects15922026/10/07 06:12:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures15932026/10/07 06:12:07 INFO Garbage collection started1594=== NAME TestClientWithDependencies1595 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1371530542/001/store) requires matching store prefix1596--- PASS: TestClientMultipleUploads (0.69s)1597=== CONT TestPush_RejectsBadRequests1598--- PASS: TestClientWithDependencies (0.67s)1599=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1600--- PASS: TestReadProxyHead (0.30s)1601=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16022026/10/07 06:12:07 INFO Received uploads request method=POST path=/1603=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16042026/10/07 06:12:07 INFO Received request for more parts method=POST path=/1605=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16062026/10/07 06:12:07 INFO Received complete multipart upload request method=POST path=/1607=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16082026/10/07 06:12:07 INFO Received uploads request method=POST path=/1609--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)1610 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1611 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1612 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1613 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1614=== CONT TestPendingClosureWriteTimeout/empty1615=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16162026/10/07 06:12:07 INFO Aborted multipart uploads count=0 kept=016172026/10/07 06:12:07 WARN Force mode enabled - objects will be deleted immediately without grace period16182026/10/07 06:12:07 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=016192026/10/07 06:12:07 INFO Vacuumed table table=pending_closures16202026/10/07 06:12:07 INFO Vacuumed table table=pending_objects16212026/10/07 06:12:07 INFO Vacuumed table table=multipart_uploads16222026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes1623--- PASS: TestService_Rustfstest (0.27s)1624=== CONT TestPendingClosureWriteTimeout/670k_objects1625=== CONT TestPendingClosureWriteTimeout/400_objects1626=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16272026/10/07 06:12:07 INFO Vacuumed table table=closures16282026/10/07 06:12:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16292026/10/07 06:12:07 INFO Vacuumed table table=objects16302026/10/07 06:12:07 INFO Uploading zvnrjm3x7fhxvfvnj14m2l3393nfaam0-ca-test (144B)16312026/10/07 06:12:07 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16322026/10/07 06:12:07 WARN Failed to register uploaded object key=zvnrjm3x7fhxvfvnj14m2l3393nfaam0.ls error="server returned 404: 404 page not found\n"16332026/10/07 06:12:07 WARN Failed to register uploaded object key=log/an0zgmiimb1dwpn0vyx4jcrpcay2cdr4-ca-test.drv error="server returned 404: 404 page not found\n"16342026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16352026/10/07 06:12:07 INFO Signed narinfos id=1 count=116362026/10/07 06:12:07 INFO Uploading 1 narinfos16372026/10/07 06:12:07 INFO Received complete push request method=POST path=/api/pushes/1/complete16382026/10/07 06:12:07 WARN Failed to register uploaded object key=zvnrjm3x7fhxvfvnj14m2l3393nfaam0.narinfo error="server returned 404: 404 page not found\n"16392026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes16402026/10/07 06:12:07 INFO Completed push id=1 objects=4 duration=12.315667ms16412026/10/07 06:12:07 INFO Upload complete. (108ms)1642=== NAME TestClientCADerivations1643 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations626319252/001/store/zvnrjm3x7fhxvfvnj14m2l3393nfaam0-ca-test1644 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1645 Compression: zstd1646 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1647 NarSize: 1441648 References: 1649 Deriver: /build/TestClientCADerivations626319252/001/store/an0zgmiimb1dwpn0vyx4jcrpcay2cdr4-ca-test.drv1650 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1651 client_ca_test.go:185: Checking for realisation files in S3...1652 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1653 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1654--- PASS: TestReadProxyInvalidPath (0.26s)1655=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale16562026-10-07 06:12:07.209 UTC [1783] ERROR: could not obtain lock on row in relation "closures"16572026-10-07 06:12:07.209 UTC [1783] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16582026-10-07 06:12:07.209 UTC [1783] ERROR: could not obtain lock on row in relation "closures"16592026-10-07 06:12:07.209 UTC [1783] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16602026-10-07 06:12:07.209 UTC [1783] ERROR: could not obtain lock on row in relation "closures"16612026-10-07 06:12:07.209 UTC [1783] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16622026-10-07 06:12:07.209 UTC [1783] ERROR: could not obtain lock on row in relation "closures"16632026-10-07 06:12:07.209 UTC [1783] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16642026-10-07 06:12:07.210 UTC [1783] ERROR: could not obtain lock on row in relation "closures"16652026-10-07 06:12:07.210 UTC [1783] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1666--- PASS: TestPush_RootsAreLockedInByteOrder (0.33s)1667=== CONT TestProxyWriteTimeout/narinfo1668=== CONT TestProxyWriteTimeout/unknown_size1669=== CONT TestProxyWriteTimeout/10_GiB_nar1670=== CONT TestProxyWriteTimeout/1_GiB_nar1671=== CONT TestParseSingleRange/none1672--- PASS: TestProxyWriteTimeout (0.09s)1673 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1674 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1675 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1676 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1677=== CONT TestParseSingleRange/end_clamped_to_size1678=== CONT TestParseSingleRange/single_byte1679=== CONT TestParseSingleRange/start_far_past_EOF1680=== CONT TestParseSingleRange/start_past_EOF1681=== CONT TestParseSingleRange/suffix_exceeds_size1682=== CONT TestParseSingleRange/suffix1683=== CONT TestParseSingleRange/closed1684=== CONT TestParseSingleRange/open-ended1685=== CONT TestParseSingleRange/multi-range_ignored1686=== CONT TestParseSingleRange/malformed_no_dash1687=== CONT TestParseSingleRange/malformed_end_before_start1688=== CONT TestParseSingleRange/unknown_unit1689=== CONT TestParseSingleRange/malformed_both_empty1690--- PASS: TestParseSingleRange (0.01s)1691 --- PASS: TestParseSingleRange/none (0.00s)1692 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1693 --- PASS: TestParseSingleRange/single_byte (0.00s)1694 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1695 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1696 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1697 --- PASS: TestParseSingleRange/suffix (0.00s)1698 --- PASS: TestParseSingleRange/closed (0.00s)1699 --- PASS: TestParseSingleRange/open-ended (0.00s)1700 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1701 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1702 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1703 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1704 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1705=== CONT TestIsValidUploadKey/narinfo1706=== CONT TestIsValidUploadKey/unknown_type1707=== CONT TestIsValidUploadKey/empty_key1708=== CONT TestIsValidUploadKey/absolute1709=== CONT TestIsValidUploadKey/traversal_nar1710=== CONT TestIsValidUploadKey/traversal1711=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1712=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1713=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1714=== CONT TestIsValidUploadKey/index.html1715=== CONT TestIsValidUploadKey/nix-cache-info1716=== CONT TestIsValidUploadKey/realisation_plus_in_output1717=== CONT TestIsValidUploadKey/realisation1718=== CONT TestIsValidUploadKey/build_log_equals1719=== CONT TestIsValidUploadKey/listing1720=== CONT TestIsValidUploadKey/nar_plain1721=== CONT TestIsValidUploadKey/nar_xz1722=== CONT TestIsValidUploadKey/build_log1723=== CONT TestIsValidUploadKey/nar_zst1724=== CONT TestIsValidUploadKey/build_log_question_mark1725=== CONT TestIsValidUploadKey/build_log_plus_in_name1726=== CONT TestIsValidUploadKey/build_log_home-manager_file1727--- PASS: TestIsValidUploadKey (0.09s)1728 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1729 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1730 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1731 --- PASS: TestIsValidUploadKey/absolute (0.00s)1732 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1733 --- PASS: TestIsValidUploadKey/traversal (0.00s)1734 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1735 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1736 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1737 --- PASS: TestIsValidUploadKey/index.html (0.00s)1738 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1739 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1740 --- PASS: TestIsValidUploadKey/realisation (0.00s)1741 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1742 --- PASS: TestIsValidUploadKey/listing (0.00s)1743 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1744 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1745 --- PASS: TestIsValidUploadKey/build_log (0.00s)1746 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1747 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1748 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1749 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1750=== CONT TestIsValidCachePath/narinfo1751=== CONT TestIsValidCachePath/index.html1752=== CONT TestIsValidCachePath/short_hash1753=== CONT TestIsValidCachePath/wrong_extension17542026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes1755=== CONT TestIsValidCachePath/leading_slash1756=== CONT TestIsValidCachePath/empty1757=== CONT TestIsValidCachePath/random_path1758=== CONT TestIsValidCachePath/invalid_char_u1759=== CONT TestIsValidCachePath/invalid_char_e1760=== CONT TestIsValidCachePath/traversal_in_middle1761=== CONT TestIsValidCachePath/traversal_parent1762=== CONT TestIsValidCachePath/realisation1763=== CONT TestIsValidCachePath/nix-cache-info1764=== CONT TestIsValidCachePath/log1765=== CONT TestIsValidCachePath/ls1766=== CONT TestIsValidCachePath/nar_xz1767=== CONT TestIsValidCachePath/nar_bz21768=== CONT TestIsValidCachePath/nar_zst1769=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1770=== CONT TestIsValidCachePath/nar_uncompressed1771=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17722026/10/07 06:12:07 INFO Received uploads request method=POST path=/1773--- PASS: TestIsValidCachePath (0.01s)1774 --- PASS: TestIsValidCachePath/narinfo (0.00s)1775 --- PASS: TestIsValidCachePath/index.html (0.00s)1776 --- PASS: TestIsValidCachePath/short_hash (0.00s)1777 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1778 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1779 --- PASS: TestIsValidCachePath/empty (0.00s)1780 --- PASS: TestIsValidCachePath/random_path (0.00s)1781 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1782 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1783 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1784 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1785 --- PASS: TestIsValidCachePath/realisation (0.00s)1786 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1787 --- PASS: TestIsValidCachePath/log (0.00s)1788 --- PASS: TestIsValidCachePath/ls (0.00s)1789 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1790 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1791 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1792 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1793 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)17942026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures17952026/10/07 06:12:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17962026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures1797--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.32s)1798=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17992026/10/07 06:12:07 INFO Received request for more parts method=POST path=/18002026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures1801=== NAME TestClientCADerivations1802 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1803 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1804 error: binary cache 's3://bucket71?endpoint=http://localhost:42317®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations626319252/001/store'1805 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11806=== NAME TestOrphanedObjectsGCStressTest1807 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1808--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.32s)1809=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18102026/10/07 06:12:07 INFO Received complete multipart upload request method=POST path=/1811--- PASS: TestClientCADerivations (0.83s)1812=== CONT TestServerTLSConfig/no_client_CA1813=== CONT TestServerTLSConfig/not_a_PEM_file1814=== CONT TestServerTLSConfig/missing_CA_file1815--- PASS: TestServerTLSConfig (0.00s)1816 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1817 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1818 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1819=== CONT TestGCEndsOnShutdown/before_the_run1820=== NAME TestOrphanedObjectsGCStressTest1821 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion18222026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures1823=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18242026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes18252026/10/07 06:12:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18262026/10/07 06:12:07 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LjE4MWEyOGY1LWQxMDEtNDY0Yy04MjM3LTA4MTYyYzliZjc2OHgxNzkxMzUzNTI3MzQ4NDE1MTcw18272026/10/07 06:12:07 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LjE4MWEyOGY1LWQxMDEtNDY0Yy04MjM3LTA4MTYyYzliZjc2OHgxNzkxMzUzNTI3MzQ4NDE1MTcw parts=11828=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1829--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.38s)1830=== CONT TestResolveDBConnectionString/flag_wins18312026/10/07 06:12:07 INFO Received complete push request method=POST path=/api/pushes/1/complete1832=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1833=== CONT TestResolveDBConnectionString/nothing_configured1834=== CONT TestResolveDBConnectionString/missing_file_is_an_error1835=== CONT TestResolveDBConnectionString/file_when_flag_empty1836=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1837--- PASS: TestResolveDBConnectionString (0.00s)1838 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1839 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1840 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1841 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1842 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18432026/10/07 06:12:07 INFO Completed push id=1 objects=4 duration=6.830128ms18442026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes18452026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes18462026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1847=== RUN TestPush_RejectsBadRequests/no_roots1848=== PAUSE TestPush_RejectsBadRequests/no_roots1849=== RUN TestPush_RejectsBadRequests/no_objects1850=== PAUSE TestPush_RejectsBadRequests/no_objects1851=== RUN TestPush_RejectsBadRequests/bad_root1852=== PAUSE TestPush_RejectsBadRequests/bad_root1853=== RUN TestPush_RejectsBadRequests/root_not_in_objects1854=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects18552026/10/07 06:12:07 INFO Signed narinfos id=1 count=11856=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18572026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18582026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18592026/10/07 06:12:07 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"18602026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18612026/10/07 06:12:07 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"18622026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18632026/10/07 06:12:07 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=118642026/10/07 06:12:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18652026/10/07 06:12:07 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1866--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.37s)1867=== CONT TestClientErrorHandling/InvalidStorePath18682026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures18692026/10/07 06:12:07 INFO Aborted multipart uploads count=0 kept=018702026/10/07 06:12:07 WARN Force mode enabled - objects will be deleted immediately without grace period18712026/10/07 06:12:07 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=018722026/10/07 06:12:07 INFO Vacuumed table table=pending_closures18732026/10/07 06:12:07 INFO Vacuumed table table=pending_objects18742026/10/07 06:12:07 INFO Vacuumed table table=multipart_uploads18752026/10/07 06:12:07 INFO Vacuumed table table=closures18762026/10/07 06:12:07 INFO Vacuumed table table=objects18772026/10/07 06:12:07 INFO Received complete push request method=POST path=/api/pushes/2/complete18782026/10/07 06:12:07 INFO Completed push id=2 objects=4 duration=3.067929ms1879--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.43s)1880=== CONT TestClientErrorHandling/ServerNotAvailable1881=== CONT TestClientErrorHandling/InvalidAuthToken18822026-10-07 06:12:07.537 UTC [1882] ERROR: Push does not exist: id=118832026-10-07 06:12:07.537 UTC [1882] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18842026-10-07 06:12:07.537 UTC [1882] STATEMENT: SELECT commit_push($1)1885--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.59s)1886=== CONT TestCacheConfigHandler/full_config,_no_issuer1887=== CONT TestCacheConfigHandler/no_signing_keys1888=== CONT TestCacheConfigHandler/no_cache_url_configured1889=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1890--- PASS: TestCacheConfigHandler (0.00s)1891 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1892 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1893 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1894 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1895=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1896=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18972026/10/07 06:12:07 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]1898=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1899=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19002026/10/07 06:12:07 WARN Authentication failed token_preview=eyJhbGciOi...kUe8nBdbMA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1901=== CONT TestService_RequireScope_OIDC/builder_may_write1902--- PASS: TestService_AuthMiddleware_OIDC (0.47s)1903 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1904 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1905 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1906 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1907=== CONT TestService_RequireScope_OIDC/reader_may_read1908=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1909=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19102026/10/07 06:12:07 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1911=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1912=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1913=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1914=== CONT TestService_RequireScope_OIDC/reader_may_not_write1915=== CONT TestService_RequireScope_OIDC/static_token_may_write1916=== CONT TestService_RequireScope_OIDC/static_token_may_admin1917=== CONT TestService_RequireScope_OIDC/ops_may_admin1918=== CONT TestService_RequireScope_OIDC/writer_implies_read1919=== CONT TestService_RequireScope_OIDC/ops_may_not_write1920=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1921=== CONT TestPush_RejectsBadRequests/no_roots19222026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes1923=== CONT TestPush_RejectsBadRequests/bad_root19242026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes1925=== CONT TestPush_RejectsBadRequests/root_not_in_objects19262026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes1927=== CONT TestPush_RejectsBadRequests/no_objects19282026/10/07 06:12:07 INFO Received push request method=POST path=/api/pushes1929--- PASS: TestService_RequireScope_OIDC (0.55s)1930 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1934 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1944--- PASS: TestPush_RejectsBadRequests (0.35s)1945 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1946 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1947 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1948 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)19492026/10/07 06:12:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19502026/10/07 06:12:07 INFO Aborted multipart uploads count=0 kept=019512026/10/07 06:12:07 WARN Force mode enabled - objects will be deleted immediately without grace period19522026/10/07 06:12:07 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/present19532026/10/07 06:12:07 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:42317/bucket95/?delete=\": context canceled"19542026/10/07 06:12:07 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LjQwZGZiY2FkLWZlNjAtNGZiMC1hM2FiLTU3N2ZlMDFjNTI0M3gxNzkxMzUzNTI3MDM3MjYwODU2 parts=1219552026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures19562026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures19572026/10/07 06:12:07 INFO Aborted multipart uploads count=0 kept=019582026/10/07 06:12:07 WARN Force mode enabled - objects will be deleted immediately without grace period1959--- PASS: TestGCEndsOnShutdown (0.00s)1960 --- PASS: TestGCEndsOnShutdown/before_the_run (0.21s)1961 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.24s)1962 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.23s)19632026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures19642026/10/07 06:12:07 INFO Aborted multipart uploads count=0 kept=019652026/10/07 06:12:07 WARN Force mode enabled - objects will be deleted immediately without grace period19662026/10/07 06:12:07 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=019672026/10/07 06:12:07 INFO Vacuumed table table=pending_closures19682026/10/07 06:12:07 INFO Vacuumed table table=pending_objects19692026/10/07 06:12:07 INFO Vacuumed table table=multipart_uploads19702026/10/07 06:12:07 INFO Vacuumed table table=closures19712026/10/07 06:12:07 INFO Vacuumed table table=objects19722026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures19732026/10/07 06:12:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.459976ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19742026/10/07 06:12:07 INFO Aborted multipart uploads count=0 kept=019752026/10/07 06:12:07 WARN Force mode enabled - objects will be deleted immediately without grace period19762026/10/07 06:12:07 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=019772026/10/07 06:12:07 INFO Vacuumed table table=pending_closures19782026/10/07 06:12:07 INFO Vacuumed table table=pending_objects19792026/10/07 06:12:07 INFO Vacuumed table table=multipart_uploads19802026/10/07 06:12:07 INFO Vacuumed table table=closures19812026/10/07 06:12:07 INFO Vacuumed table table=objects19822026/10/07 06:12:07 INFO lead: released remote=192.0.2.1:12341983--- PASS: TestLeadEndsOnShutdown (1.57s)1984--- PASS: TestDeleteClosuresRacingPins (1.59s)1985--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1986 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.27s)1987 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)1988=== NAME TestOrphanedObjectsGCStressTest1989 orphaned_objects_gc_test.go:503: Stress test completed successfully:1990 orphaned_objects_gc_test.go:504: - Active objects preserved: 201991 orphaned_objects_gc_test.go:505: - Objects deleted: 2101992 orphaned_objects_gc_test.go:506: - Total GC'd: 2101993--- PASS: TestOrphanedObjectsGCStressTest (3.03s)19942026/10/07 06:12:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19952026/10/07 06:12:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19962026/10/07 06:12:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19972026/10/07 06:12:07 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LmJlNjg3YWVlLWQwYjUtNGRlNi05YzM5LTU3MjZjMzg4YWVmY3gxNzkxMzUzNTI3Mjc3Njc5MzEw parts=1219982026/10/07 06:12:07 INFO Received uploads request method=POST path=/api/pending_closures1999--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.87s)20002026/10/07 06:12:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.271668ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20012026/10/07 06:12:07 INFO lead: released remote=192.0.2.1:12342002--- PASS: TestUploadHandlersRejectOversizedBody (0.24s)2003 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)2004 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2005 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.71s)20062026/10/07 06:12:07 INFO lead: acquired remote=192.0.2.1:12342007--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2008 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.85s)2009 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.81s)20102026/10/07 06:12:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20112026/10/07 06:12:08 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LmM1ZWY0MGFmLWI1OGItNGFkOC04Y2Q1LWUwNTUxMDQ5ZGFmM3gxNzkxMzUzNTI3NjAwODkyODkw error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20122026/10/07 06:12:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWY3ZjU3N2YtNGFiNi00OGM0LTliMTgtNjg3MzNhY2YzNDk0LmE2ODY4ZDEwLWVmNmQtNGFkNC05YTE0LTA1OTY5NTEyYmE0ZngxNzkxMzUzNTI3NTkzMTA0NjIz parts=1220132026/10/07 06:12:08 INFO Received cleanup request method=DELETE path=/api/pending_closures20142026/10/07 06:12:08 INFO Aborted multipart uploads count=1 kept=02015--- PASS: TestRedundantMultipartUpload (1.54s)2016--- PASS: TestPendingClosureWriteTimeout (0.09s)2017 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2018 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2019 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2020 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.16s)20212026/10/07 06:12:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=728.230895ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20222026/10/07 06:12:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02023=== NAME TestClientIntegration2024 client_integration_test.go:323: Objects in database after GC:2025 client_integration_test.go:323: Successfully deleted all objects with GC --force20262026/10/07 06:12:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.478875374s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2027--- PASS: TestClientIntegration (2.62s)20282026/10/07 06:12:09 INFO lead: released remote=192.0.2.1:12342029--- PASS: TestLeadElectsOneAndHandsOver (2.73s)20302026/10/07 06:12:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020312026/10/07 06:12:09 INFO Received create pin request method=POST path=/api/pins/myapp20322026/10/07 06:12:09 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2667362631/001/store/6i1zs7jmsab63mis6vf39xdqqa2h2bj0-pinned-file.txt narinfo_key=6i1zs7jmsab63mis6vf39xdqqa2h2bj0.narinfo20332026/10/07 06:12:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures20342026/10/07 06:12:09 INFO Garbage collection started20352026/10/07 06:12:09 INFO Aborted multipart uploads count=0 kept=020362026/10/07 06:12:09 WARN Force mode enabled - objects will be deleted immediately without grace period20372026/10/07 06:12:09 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=020382026/10/07 06:12:09 INFO Vacuumed table table=pending_closures20392026/10/07 06:12:09 INFO Vacuumed table table=pending_objects20402026/10/07 06:12:09 INFO Vacuumed table table=multipart_uploads20412026/10/07 06:12:09 INFO Vacuumed table table=closures20422026/10/07 06:12:09 INFO Vacuumed table table=objects20432026/10/07 06:12:09 WARN Rate limiter enabled after throttle name=s3-test rate=520442026/10/07 06:12:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2045=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2046 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102047 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002048--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.33s)20492026/10/07 06:12:10 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-config20502026/10/07 06:12:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.486348ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20512026/10/07 06:12:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.167826ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2052=== NAME TestPinProtectsFromGC2053 client_integration_test.go:840: Pin successfully protected closure from garbage collection2054--- PASS: TestPinProtectsFromGC (4.77s)20552026/10/07 06:12:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=850.437368ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2056--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.52s)20572026/10/07 06:12:11 INFO Aborted multipart uploads count=1 kept=020582026/10/07 06:12:11 INFO Received cleanup request method=DELETE path=/api/pending_closures2059--- PASS: TestConnectWaitsForAPeerMigration (5.20s)20602026/10/07 06:12:11 INFO Aborted multipart uploads count=1 kept=02061--- PASS: TestPendingCleanupUsesOneCutoff (6.86s)20622026/10/07 06:12:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.629762004s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20632026/10/07 06:12:13 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"20642026/10/07 06:12:13 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-config20652026/10/07 06:12:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.524296ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20662026/10/07 06:12:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.325759ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20672026/10/07 06:12:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=777.752611ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20682026/10/07 06:12:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.713512142s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20692026/10/07 06:12:16 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_closures20702026/10/07 06:12:17 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.586485ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20712026/10/07 06:12:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=389.619588ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20722026/10/07 06:12:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=773.198149ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20732026/10/07 06:12:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.749658468s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2074--- PASS: TestClientErrorHandling (0.00s)2075 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2076 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.26s)2077 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.67s)2078PASS2079{"timestamp":"2026-10-07T06:12:20.177786243Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56910","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(398)"}20802026-10-07 06:12:20.550 UTC [129] LOG: received smart shutdown request20812026-10-07 06:12:20.554 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120822026-10-07 06:12:20.562 UTC [134] LOG: shutting down20832026-10-07 06:12:20.563 UTC [134] LOG: checkpoint starting: shutdown immediate20842026-10-07 06:12:21.820 UTC [134] LOG: checkpoint complete: wrote 10773 buffers (65.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.281 s, sync=0.922 s, total=1.259 s; sync files=34045, longest=0.013 s, average=0.001 s; distance=531502 kB, estimate=531502 kB; lsn=0/21E71688, redo lsn=0/21E7168820852026-10-07 06:12:21.906 UTC [129] LOG: database system is shut down2086Running OIDC tests...2087=== RUN TestAudienceForIssuer2088=== PAUSE TestAudienceForIssuer2089=== RUN TestGlobMatch2090=== PAUSE TestGlobMatch2091=== RUN TestValidateToken_ValidToken2092=== PAUSE TestValidateToken_ValidToken2093=== RUN TestValidateToken_WrongAudience2094=== PAUSE TestValidateToken_WrongAudience2095=== RUN TestValidateToken_Expired2096=== PAUSE TestValidateToken_Expired2097=== RUN TestValidateToken_BoundClaimsMismatch2098=== PAUSE TestValidateToken_BoundClaimsMismatch2099=== RUN TestValidateToken_BoundSubjectMismatch2100=== PAUSE TestValidateToken_BoundSubjectMismatch2101=== RUN TestValidateToken_MultipleProviders2102=== PAUSE TestValidateToken_MultipleProviders2103=== RUN TestValidateToken_NoMatchingProvider2104=== PAUSE TestValidateToken_NoMatchingProvider2105=== RUN TestValidateToken_KubernetesServiceAccount2106=== PAUSE TestValidateToken_KubernetesServiceAccount2107=== RUN TestNewValidator_KubernetesRequiresCA2108=== PAUSE TestNewValidator_KubernetesRequiresCA2109=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2110=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2111=== RUN TestPins_ReservedForMatchingRule2112=== PAUSE TestPins_ReservedForMatchingRule2113=== RUN TestPins_TopLevelShorthand2114=== PAUSE TestPins_TopLevelShorthand2115=== RUN TestPins_ConfigValidation2116=== PAUSE TestPins_ConfigValidation2117=== RUN TestScopes_LegacyProviderDefaultsToWrite2118=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2119=== RUN TestScopes_Rules2120=== PAUSE TestScopes_Rules2121=== RUN TestScopes_ConfigValidation2122=== PAUSE TestScopes_ConfigValidation2123=== CONT TestAudienceForIssuer2124=== CONT TestValidateToken_BoundClaimsMismatch2125=== CONT TestValidateToken_KubernetesServiceAccount2126=== CONT TestScopes_ConfigValidation2127=== CONT TestScopes_Rules2128=== CONT TestScopes_LegacyProviderDefaultsToWrite2129=== CONT TestPins_ConfigValidation2130--- PASS: TestAudienceForIssuer (0.00s)2131=== CONT TestPins_TopLevelShorthand2132--- PASS: TestPins_ConfigValidation (0.00s)2133--- PASS: TestScopes_ConfigValidation (0.00s)2134=== CONT TestValidateToken_ValidToken2135=== CONT TestPins_ReservedForMatchingRule2136=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2137=== CONT TestGlobMatch2138=== CONT TestNewValidator_KubernetesRequiresCA2139=== CONT TestValidateToken_Expired2140=== CONT TestValidateToken_MultipleProviders2141=== CONT TestValidateToken_BoundSubjectMismatch2142=== CONT TestValidateToken_NoMatchingProvider2143=== CONT TestValidateToken_WrongAudience2144=== RUN TestGlobMatch/foo_foo2145=== PAUSE TestGlobMatch/foo_foo2146=== RUN TestGlobMatch/foo_bar2147=== PAUSE TestGlobMatch/foo_bar2148=== RUN TestGlobMatch/*_2149=== PAUSE TestGlobMatch/*_2150=== RUN TestGlobMatch/*_anything2151=== PAUSE TestGlobMatch/*_anything2152=== RUN TestGlobMatch/foo*_foo2153=== PAUSE TestGlobMatch/foo*_foo2154=== RUN TestGlobMatch/foo*_foobar2155=== PAUSE TestGlobMatch/foo*_foobar2156=== RUN TestGlobMatch/foo*_bar2157=== PAUSE TestGlobMatch/foo*_bar2158=== RUN TestGlobMatch/*bar_bar2159=== PAUSE TestGlobMatch/*bar_bar2160=== RUN TestGlobMatch/*bar_foobar2161=== PAUSE TestGlobMatch/*bar_foobar2162=== RUN TestGlobMatch/*bar_foo2163=== PAUSE TestGlobMatch/*bar_foo2164=== RUN TestGlobMatch/foo*bar_foobar2165=== PAUSE TestGlobMatch/foo*bar_foobar2166=== RUN TestGlobMatch/foo*bar_foo123bar2167=== PAUSE TestGlobMatch/foo*bar_foo123bar2168=== RUN TestGlobMatch/foo*bar_foobarbaz2169=== PAUSE TestGlobMatch/foo*bar_foobarbaz2170=== RUN TestGlobMatch/*/*_foo/bar2171=== PAUSE TestGlobMatch/*/*_foo/bar2172=== RUN TestGlobMatch/*/*_foo2173=== PAUSE TestGlobMatch/*/*_foo2174=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2175=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2176=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02177=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02178=== RUN TestGlobMatch/refs/*/main_refs/heads/main2179=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2180=== RUN TestGlobMatch/fo?_foo2181=== PAUSE TestGlobMatch/fo?_foo2182=== RUN TestGlobMatch/fo?_fo2183=== PAUSE TestGlobMatch/fo?_fo2184=== RUN TestGlobMatch/fo?_fooo2185=== PAUSE TestGlobMatch/fo?_fooo2186=== RUN TestGlobMatch/?oo_foo2187=== PAUSE TestGlobMatch/?oo_foo2188=== RUN TestGlobMatch/?oo_boo2189=== PAUSE TestGlobMatch/?oo_boo2190=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2191=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2192=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2193=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2194=== CONT TestGlobMatch/foo_foo2195=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2196=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2197=== CONT TestGlobMatch/foo*bar_foo123bar2198=== CONT TestGlobMatch/foo*bar_foobar2199=== CONT TestGlobMatch/*bar_foo2200=== CONT TestGlobMatch/*bar_foobar2201=== CONT TestGlobMatch/*bar_bar2202=== CONT TestGlobMatch/foo*_bar2203=== CONT TestGlobMatch/foo*_foobar2204=== CONT TestGlobMatch/foo*_foo2205=== CONT TestGlobMatch/*_anything2206=== CONT TestGlobMatch/*_2207=== CONT TestGlobMatch/foo_bar2208=== CONT TestGlobMatch/fo?_foo2209=== CONT TestGlobMatch/?oo_boo2210=== CONT TestGlobMatch/?oo_foo2211=== CONT TestGlobMatch/fo?_fooo2212=== CONT TestGlobMatch/fo?_fo2213=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2214=== CONT TestGlobMatch/refs/*/main_refs/heads/main2215=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02216=== CONT TestGlobMatch/*/*_foo2217=== CONT TestGlobMatch/*/*_foo/bar2218=== CONT TestGlobMatch/foo*bar_foobarbaz2219--- PASS: TestGlobMatch (0.00s)2220 --- PASS: TestGlobMatch/foo_foo (0.00s)2221 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2222 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2223 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2224 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2225 --- PASS: TestGlobMatch/*bar_foo (0.00s)2226 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2227 --- PASS: TestGlobMatch/*bar_bar (0.00s)2228 --- PASS: TestGlobMatch/foo*_bar (0.00s)2229 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2230 --- PASS: TestGlobMatch/foo*_foo (0.00s)2231 --- PASS: TestGlobMatch/*_anything (0.00s)2232 --- PASS: TestGlobMatch/*_ (0.00s)2233 --- PASS: TestGlobMatch/foo_bar (0.00s)2234 --- PASS: TestGlobMatch/fo?_foo (0.00s)2235 --- PASS: TestGlobMatch/?oo_boo (0.00s)2236 --- PASS: TestGlobMatch/?oo_foo (0.00s)2237 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2238 --- PASS: TestGlobMatch/fo?_fo (0.00s)2239 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2240 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2241 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2242 --- PASS: TestGlobMatch/*/*_foo (0.00s)2243 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2244 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)22452026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34989/oidc2246--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)22472026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41569/oidc2248--- PASS: TestValidateToken_Expired (0.02s)22492026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33373/oidc2250--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)22512026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38337/oidc2252--- PASS: TestValidateToken_WrongAudience (0.03s)22532026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42075/oidc2254--- PASS: TestValidateToken_ValidToken (0.04s)22552026/10/07 06:12:24 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:347732256--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)22572026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42361/oidc22582026/10/07 06:12:24 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36421/oidc2259--- PASS: TestPins_ReservedForMatchingRule (0.09s)2260--- PASS: TestValidateToken_NoMatchingProvider (0.09s)22612026/10/07 06:12:24 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232262--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)22632026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44157/oidc2264--- PASS: TestValidateToken_BoundSubjectMismatch (0.12s)22652026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38237/oidc22662026/10/07 06:12:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40123/oidc2267--- PASS: TestPins_TopLevelShorthand (0.12s)22682026/10/07 06:12:24 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44371/oidc22692026/10/07 06:12:24 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39651/oidc2270--- PASS: TestScopes_Rules (0.13s)2271--- PASS: TestValidateToken_MultipleProviders (0.13s)22722026/10/07 06:12:24 http: TLS handshake error from 127.0.0.1:57376: remote error: tls: bad certificate2273--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)2274PASS2275Running hook tests...2276=== RUN TestSendPathsEmpty2277=== PAUSE TestSendPathsEmpty2278=== RUN TestQueueEnqueueAndFetch2279=== PAUSE TestQueueEnqueueAndFetch2280=== RUN TestQueueDeduplication2281=== PAUSE TestQueueDeduplication2282=== RUN TestQueueRemove2283=== PAUSE TestQueueRemove2284=== RUN TestQueueFetchBatchLimit2285=== PAUSE TestQueueFetchBatchLimit2286=== RUN TestQueueRetryMovesToBack2287=== PAUSE TestQueueRetryMovesToBack2288=== RUN TestQueueFetchRemoveLifecycle2289=== PAUSE TestQueueFetchRemoveLifecycle2290=== RUN TestQueueConcurrentWriters2291=== PAUSE TestQueueConcurrentWriters2292=== RUN TestQueueRemoveLargeClosure2293=== PAUSE TestQueueRemoveLargeClosure2294=== RUN TestServerClientIntegration2295=== PAUSE TestServerClientIntegration2296=== RUN TestServerQueueError2297=== PAUSE TestServerQueueError2298=== RUN TestGetListenerSocketActivation2299 server_test.go:210: === RUN TestGetListenerSocketActivation2300 --- PASS: TestGetListenerSocketActivation (0.00s)2301 PASS2302 2303--- PASS: TestGetListenerSocketActivation (0.01s)2304=== RUN TestDrainIsolatesPoisonPath2305=== PAUSE TestDrainIsolatesPoisonPath2306=== RUN TestRunNotBlockedByPoisonHead2307=== PAUSE TestRunNotBlockedByPoisonHead2308=== RUN TestDrainGivesUpWhenServerDown2309=== PAUSE TestDrainGivesUpWhenServerDown2310=== RUN TestFailedPathPrunedByLaterClosure2311=== PAUSE TestFailedPathPrunedByLaterClosure2312=== RUN TestWorkerUploadsAndRemoves2313=== PAUSE TestWorkerUploadsAndRemoves2314=== RUN TestWorkerSkipsGCdPaths2315=== PAUSE TestWorkerSkipsGCdPaths2316=== RUN TestWorkerPrunesClosureDeps2317=== PAUSE TestWorkerPrunesClosureDeps2318=== RUN TestDrainTimeout2319=== PAUSE TestDrainTimeout2320=== CONT TestSendPathsEmpty2321=== CONT TestDrainTimeout2322--- PASS: TestSendPathsEmpty (0.00s)2323=== CONT TestServerQueueError2324=== CONT TestQueueFetchBatchLimit2325=== CONT TestQueueRemove2326=== CONT TestQueueDeduplication2327=== CONT TestQueueEnqueueAndFetch2328=== CONT TestWorkerSkipsGCdPaths2329=== CONT TestWorkerPrunesClosureDeps2330=== CONT TestRunNotBlockedByPoisonHead2331=== CONT TestDrainGivesUpWhenServerDown23322026/10/07 06:12:24 ERROR Failed to queue paths error="permission denied" count=12333=== CONT TestQueueRemoveLargeClosure2334=== CONT TestServerClientIntegration2335=== CONT TestDrainIsolatesPoisonPath2336=== CONT TestWorkerUploadsAndRemoves2337=== CONT TestQueueConcurrentWriters2338=== CONT TestQueueFetchRemoveLifecycle2339=== CONT TestFailedPathPrunedByLaterClosure2340=== CONT TestQueueRetryMovesToBack2341--- PASS: TestServerQueueError (0.00s)2342--- PASS: TestServerClientIntegration (0.00s)23432026/10/07 06:12:24 INFO Uploading batch count=423442026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=423452026/10/07 06:12:24 INFO Uploading batch count=223462026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=223472026/10/07 06:12:24 INFO Uploading batch count=223482026/10/07 06:12:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1421687072/002/a23492026/10/07 06:12:24 INFO Uploading batch count=123502026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=123512026/10/07 06:12:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath104100022/002/bbb23522026/10/07 06:12:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1421687072/002/b23532026/10/07 06:12:24 INFO Uploading batch count=12354--- PASS: TestQueueFetchBatchLimit (0.02s)23552026/10/07 06:12:24 INFO Upload queue status pending=223562026/10/07 06:12:24 INFO Upload queue status pending=323572026/10/07 06:12:24 INFO Upload queue status pending=223582026/10/07 06:12:24 INFO Uploading batch count=223592026/10/07 06:12:24 INFO Uploading batch count=123602026/10/07 06:12:24 INFO Upload queue status pending=223612026/10/07 06:12:24 INFO Uploading batch count=123622026/10/07 06:12:24 INFO Uploading batch count=223632026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=22364--- PASS: TestQueueEnqueueAndFetch (0.02s)23652026/10/07 06:12:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1421687072/002/c2366--- PASS: TestQueueDeduplication (0.02s)23672026/10/07 06:12:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2419143915/002/nonexistent23682026/10/07 06:12:24 INFO Uploading batch count=123692026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=12370--- PASS: TestQueueRetryMovesToBack (0.02s)23712026/10/07 06:12:24 INFO Uploading batch count=123722026/10/07 06:12:24 INFO Uploading batch count=123732026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=123742026/10/07 06:12:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1421687072/002/d2375--- PASS: TestQueueRemove (0.02s)2376--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23772026/10/07 06:12:24 INFO Uploading batch count=223782026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=223792026/10/07 06:12:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1421687072/002/e23802026/10/07 06:12:24 INFO Uploading batch count=123812026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=123822026/10/07 06:12:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1421687072/002/f2383--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23842026/10/07 06:12:24 ERROR Drain finished with paths left in queue remaining=1023852026/10/07 06:12:24 INFO Uploading batch count=123862026/10/07 06:12:24 ERROR Upload failed error="upload failed" count=123872026/10/07 06:12:24 ERROR Drain finished with paths left in queue remaining=12388--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2389--- PASS: TestDrainIsolatesPoisonPath (0.03s)2390--- PASS: TestWorkerSkipsGCdPaths (0.04s)2391--- PASS: TestWorkerUploadsAndRemoves (0.04s)2392--- PASS: TestWorkerPrunesClosureDeps (0.04s)2393--- PASS: TestQueueRemoveLargeClosure (0.06s)23942026/10/07 06:12:25 ERROR Upload failed error="context deadline exceeded" count=223952026/10/07 06:12:25 ERROR Drain finished with paths left in queue remaining=42396--- PASS: TestDrainTimeout (0.22s)2397--- PASS: TestQueueConcurrentWriters (0.28s)23982026/10/07 06:12:25 INFO Uploading batch count=123992026/10/07 06:12:25 INFO Uploading batch count=124002026/10/07 06:12:25 INFO Uploading batch count=124012026/10/07 06:12:25 ERROR Upload failed error="upload failed" count=124022026/10/07 06:12:25 INFO Uploading batch count=124032026/10/07 06:12:25 ERROR Upload failed error="upload failed" count=124042026/10/07 06:12:25 INFO Uploading batch count=124052026/10/07 06:12:25 ERROR Upload failed error="upload failed" count=124062026/10/07 06:12:25 INFO Uploading batch count=124072026/10/07 06:12:25 ERROR Upload failed error="upload failed" count=124082026/10/07 06:12:25 ERROR Drain finished with paths left in queue remaining=12409--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2410PASS2411Running signing tests...2412=== RUN TestExternalSigner2413=== PAUSE TestExternalSigner2414=== RUN TestExternalSignerWrongPublicKey2415=== PAUSE TestExternalSignerWrongPublicKey2416=== RUN TestExternalSignerErrors2417=== PAUSE TestExternalSignerErrors2418=== RUN TestExternalSignerRestartsAfterCrash2419=== PAUSE TestExternalSignerRestartsAfterCrash2420=== RUN TestExternalSignerProgramErrorKeepsProcess2421=== PAUSE TestExternalSignerProgramErrorKeepsProcess2422=== RUN TestExternalSignerClose2423=== PAUSE TestExternalSignerClose2424=== RUN TestExternalSignerRejectsInvalidPublicKey2425=== PAUSE TestExternalSignerRejectsInvalidPublicKey2426=== RUN TestExternalSignerCancellation2427=== PAUSE TestExternalSignerCancellation2428=== RUN TestGenerateFingerprint2429=== PAUSE TestGenerateFingerprint2430=== RUN TestParseSigningKey2431=== PAUSE TestParseSigningKey2432=== RUN TestSign2433=== PAUSE TestSign2434=== RUN TestSignBatch2435=== PAUSE TestSignBatch2436=== RUN TestNilKeyPublicKey2437=== PAUSE TestNilKeyPublicKey2438=== RUN TestSignErrors2439=== PAUSE TestSignErrors2440=== CONT TestExternalSigner2441=== CONT TestExternalSignerCancellation2442=== CONT TestExternalSignerProgramErrorKeepsProcess2443=== CONT TestSignBatch2444=== CONT TestSignErrors2445=== CONT TestNilKeyPublicKey2446--- PASS: TestNilKeyPublicKey (0.00s)2447=== CONT TestExternalSignerRejectsInvalidPublicKey2448=== CONT TestParseSigningKey2449=== CONT TestSign2450=== CONT TestGenerateFingerprint2451=== CONT TestExternalSignerClose2452=== CONT TestExternalSignerErrors2453=== CONT TestExternalSignerRestartsAfterCrash2454=== CONT TestExternalSignerWrongPublicKey2455=== RUN TestExternalSignerRejectsInvalidPublicKey/#002456=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002457=== RUN TestGenerateFingerprint/basic_with_references2458=== PAUSE TestGenerateFingerprint/basic_with_references2459=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2460=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2461--- PASS: TestSign (0.00s)2462=== RUN TestParseSigningKey/valid_32-byte_key2463=== PAUSE TestParseSigningKey/valid_32-byte_key2464=== RUN TestGenerateFingerprint/no_references2465=== RUN TestExternalSignerErrors/exit_on_request2466=== PAUSE TestExternalSignerErrors/exit_on_request2467=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2468=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2469=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2470--- PASS: TestSignBatch (0.00s)2471=== RUN TestSignErrors/nil_key2472=== PAUSE TestSignErrors/nil_key2473=== RUN TestSignErrors/nil_narinfo2474=== PAUSE TestSignErrors/nil_narinfo2475=== RUN TestSignErrors/invalid_narinfo2476=== PAUSE TestGenerateFingerprint/no_references2477=== RUN TestExternalSignerErrors/invalid_JSON2478=== PAUSE TestExternalSignerErrors/invalid_JSON2479=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2480=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2481=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2482=== PAUSE TestSignErrors/invalid_narinfo2483=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2484=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2485=== RUN TestExternalSignerErrors/null2486=== PAUSE TestExternalSignerErrors/null2487=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2488=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2489=== RUN TestParseSigningKey/no_colon2490=== PAUSE TestParseSigningKey/no_colon2491=== RUN TestParseSigningKey/empty_name2492=== PAUSE TestParseSigningKey/empty_name2493=== RUN TestParseSigningKey/invalid_base642494=== PAUSE TestParseSigningKey/invalid_base642495=== RUN TestParseSigningKey/wrong_length2496=== RUN TestSignErrors/canceled2497=== PAUSE TestSignErrors/canceled2498=== CONT TestSignErrors/nil_key2499=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2500=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2501=== CONT TestSignErrors/canceled2502=== RUN TestExternalSignerErrors/program_error2503=== PAUSE TestExternalSignerErrors/program_error2504=== RUN TestExternalSignerErrors/wrong_shape2505=== CONT TestExternalSignerRejectsInvalidPublicKey/#002506=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2507=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2508=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2509=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2510--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2511 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2512 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2513 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2514 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2515 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2516=== PAUSE TestParseSigningKey/wrong_length2517=== CONT TestParseSigningKey/valid_32-byte_key2518=== CONT TestParseSigningKey/invalid_base642519=== CONT TestSignErrors/invalid_narinfo2520=== CONT TestSignErrors/nil_narinfo2521=== RUN TestGenerateFingerprint/invalid_nar_hash_length2522=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2523=== RUN TestGenerateFingerprint/invalid_store_path_prefix2524=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2525=== PAUSE TestExternalSignerErrors/wrong_shape2526=== CONT TestParseSigningKey/empty_name2527=== CONT TestParseSigningKey/no_colon2528=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2529=== CONT TestParseSigningKey/wrong_length2530--- PASS: TestExternalSignerWrongPublicKey (0.00s)2531=== RUN TestGenerateFingerprint/invalid_reference_prefix2532=== RUN TestExternalSignerErrors/missing_signatures2533--- PASS: TestSignErrors (0.00s)2534 --- PASS: TestSignErrors/nil_key (0.00s)2535 --- PASS: TestSignErrors/canceled (0.00s)2536 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2537 --- PASS: TestSignErrors/nil_narinfo (0.00s)2538=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2539=== PAUSE TestExternalSignerErrors/missing_signatures2540--- PASS: TestParseSigningKey (0.00s)2541 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2542 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2543 --- PASS: TestParseSigningKey/empty_name (0.00s)2544 --- PASS: TestParseSigningKey/no_colon (0.00s)2545 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2546 --- PASS: TestParseSigningKey/wrong_length (0.00s)2547=== RUN TestExternalSignerErrors/wrong_signatures_shape2548=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2549=== RUN TestExternalSignerErrors/wrong_signature_name2550=== PAUSE TestExternalSignerErrors/wrong_signature_name2551=== RUN TestExternalSignerErrors/wrong_signature_length2552--- PASS: TestExternalSignerClose (0.00s)2553--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2554=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2555=== CONT TestGenerateFingerprint/invalid_nar_hash_length2556=== CONT TestGenerateFingerprint/invalid_reference_prefix2557=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2558=== CONT TestGenerateFingerprint/no_references2559=== CONT TestGenerateFingerprint/invalid_store_path_prefix2560=== CONT TestGenerateFingerprint/basic_with_references2561--- PASS: TestGenerateFingerprint (0.00s)2562 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2563 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2564 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2565 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2566 --- PASS: TestGenerateFingerprint/no_references (0.00s)2567 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2568 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2569=== PAUSE TestExternalSignerErrors/wrong_signature_length2570=== RUN TestExternalSignerErrors/exit_at_startup2571=== PAUSE TestExternalSignerErrors/exit_at_startup2572=== RUN TestExternalSignerErrors/wrong_id2573=== PAUSE TestExternalSignerErrors/wrong_id2574=== RUN TestExternalSignerErrors/missing_signature_name2575=== PAUSE TestExternalSignerErrors/missing_signature_name2576=== RUN TestExternalSignerErrors/invalid_signature_base642577=== PAUSE TestExternalSignerErrors/invalid_signature_base642578=== RUN TestExternalSignerErrors/null_signatures2579=== PAUSE TestExternalSignerErrors/null_signatures2580=== RUN TestExternalSignerErrors/too_few_signatures2581=== PAUSE TestExternalSignerErrors/too_few_signatures2582=== RUN TestExternalSignerErrors/unrequested_key2583=== PAUSE TestExternalSignerErrors/unrequested_key2584=== CONT TestExternalSignerErrors/exit_on_request2585=== CONT TestExternalSignerErrors/missing_signature_name2586=== CONT TestExternalSignerErrors/wrong_signature_length2587=== CONT TestExternalSignerErrors/unrequested_key2588=== CONT TestExternalSignerErrors/too_few_signatures2589=== CONT TestExternalSignerErrors/null_signatures2590=== CONT TestExternalSignerErrors/wrong_id2591=== CONT TestExternalSignerErrors/exit_at_startup2592=== CONT TestExternalSignerErrors/wrong_shape2593=== CONT TestExternalSignerErrors/wrong_signature_name2594=== CONT TestExternalSignerErrors/wrong_signatures_shape2595=== CONT TestExternalSignerErrors/missing_signatures2596=== CONT TestExternalSignerErrors/null2597=== CONT TestExternalSignerErrors/invalid_JSON2598=== CONT TestExternalSignerErrors/program_error2599=== CONT TestExternalSignerErrors/invalid_signature_base642600--- PASS: TestExternalSigner (0.01s)2601--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2602--- PASS: TestExternalSignerErrors (0.00s)2603 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2604 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2605 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2606 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2607 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2608 --- PASS: TestExternalSignerErrors/program_error (0.01s)2609 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2610 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2611 --- PASS: TestExternalSignerErrors/null (0.01s)2612 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2613 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2614 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2615 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2616 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2617 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2618 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2619--- PASS: TestExternalSignerCancellation (0.02s)2620PASS2621Running OpenBao signer tests...2622=== RUN TestSign2623=== PAUSE TestSign2624=== RUN TestSignErrors2625=== PAUSE TestSignErrors2626=== RUN TestServe2627=== PAUSE TestServe2628=== RUN TestServeRejectsGarbage2629=== PAUSE TestServeRejectsGarbage2630=== CONT TestSign2631=== CONT TestServe2632=== CONT TestSignErrors2633=== CONT TestServeRejectsGarbage2634--- PASS: TestServeRejectsGarbage (0.00s)2635=== RUN TestSignErrors/http_error2636=== PAUSE TestSignErrors/http_error2637=== RUN TestSignErrors/invalid_json2638=== PAUSE TestSignErrors/invalid_json2639=== RUN TestSignErrors/no_prefix2640=== PAUSE TestSignErrors/no_prefix2641=== RUN TestSignErrors/invalid_base642642=== PAUSE TestSignErrors/invalid_base642643=== CONT TestSignErrors/http_error2644=== CONT TestSignErrors/no_prefix2645--- PASS: TestServe (0.00s)2646=== CONT TestSignErrors/invalid_json2647=== CONT TestSignErrors/invalid_base642648--- PASS: TestSign (0.00s)2649--- PASS: TestSignErrors (0.00s)2650 --- PASS: TestSignErrors/http_error (0.00s)2651 --- PASS: TestSignErrors/invalid_json (0.00s)2652 --- PASS: TestSignErrors/invalid_base64 (0.00s)2653 --- PASS: TestSignErrors/no_prefix (0.00s)2654PASS