niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #278
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96--- PASS: TestShellSplit (0.00s)97=== CONT TestEncodeNixBase32WithRealHash98--- PASS: TestEncodeNixBase32WithRealHash (0.00s)99=== CONT TestFileTokenMissing100=== CONT TestScriptTokenEmptyCommand101--- PASS: TestScriptTokenEmptyCommand (0.00s)102=== CONT TestFileTokenReadsAndCaches103=== CONT TestScriptTokenScriptFails104=== CONT TestScriptTokenBadJSON105=== CONT TestScriptTokenEmptyToken106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestScriptTokenNoExpiryRerunsEveryCall108=== CONT TestFileTokenEmpty109=== CONT TestPathInfoCACompatibility110=== CONT TestStaticToken111--- PASS: TestDoServerRequestAttachesToken (0.00s)112=== CONT TestSetClientTLSErrors113=== CONT TestSetClientTLSDoesNotMutateDefaultTransport114--- PASS: TestFileTokenMissing (0.00s)115--- PASS: TestFileTokenReadsAndCaches (0.00s)116=== RUN TestPathInfoCACompatibility/null_ca_field117--- PASS: TestStaticToken (0.00s)118=== CONT TestSetClientTLS119=== RUN TestSetClientTLSErrors/missing_cert_file120=== PAUSE TestPathInfoCACompatibility/null_ca_field121=== PAUSE TestSetClientTLSErrors/missing_cert_file122=== RUN TestSetClientTLSErrors/missing_key_file123=== PAUSE TestSetClientTLSErrors/missing_key_file124=== RUN TestSetClientTLSErrors/missing_ca_file125=== PAUSE TestSetClientTLSErrors/missing_ca_file126=== RUN TestPathInfoCACompatibility/old_string_format_-_text127=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text128=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive129=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive130=== RUN TestPathInfoCACompatibility/new_structured_format_-_text131=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text132=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method133--- PASS: TestScriptTokenScriptFails (0.00s)134=== CONT TestClientSignaturesByStorePath135=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method136--- PASS: TestClientSignaturesByStorePath (0.00s)137=== CONT TestStreamPushRequestLine138=== RUN TestSetClientTLSErrors/invalid_ca_file139=== PAUSE TestSetClientTLSErrors/invalid_ca_file140=== CONT TestStreamPushReportsSignatures141=== CONT TestStreamPushGivesUpOnDeadServer1422026/09/29 08:18:06 ERROR Upload failed error="connection refused" count=20143--- PASS: TestFileTokenEmpty (0.00s)1442026/09/29 08:18:06 ERROR Server seems unavailable, giving up on batch untried=171452026/09/29 08:18:06 ERROR Upload failed error=boom count=1146=== CONT TestStreamPushIsolatesFailures1472026/09/29 08:18:06 ERROR Upload failed error="bad path" count=3148--- PASS: TestStreamPushIsolatesFailures (0.00s)149=== CONT TestStreamPushBatchesUnderLoad1502026/09/29 08:18:06 ERROR Upload failed error=boom count=1151--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)152=== CONT TestStreamPushReportsEveryPath153--- PASS: TestStreamPushReportsSignatures (0.00s)154=== CONT TestShellSplitErrors155--- PASS: TestShellSplitErrors (0.00s)156=== CONT TestGetStorePathHash157=== RUN TestGetStorePathHash/valid_store_path158=== PAUSE TestGetStorePathHash/valid_store_path159=== RUN TestGetStorePathHash/basename_without_hyphen_should_error160=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error161=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error162=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error163=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error164=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error165--- PASS: TestStreamPushReportsEveryPath (0.00s)166=== CONT TestConvertHashToNix32167=== RUN TestConvertHashToNix32/SRI_format_to_Nix32168=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32169=== RUN TestConvertHashToNix32/already_Nix32_format170=== PAUSE TestConvertHashToNix32/already_Nix32_format171=== RUN TestConvertHashToNix32/invalid_format172=== PAUSE TestConvertHashToNix32/invalid_format173=== CONT TestParsePathInfoJSONMultiplePaths174=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths175=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths176=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths177=== RUN TestSetClientTLS/rejects_connection_without_client_cert178=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert179=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA180=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA181=== RUN TestSetClientTLS/preserves_debug_logging_transport182=== PAUSE TestSetClientTLS/preserves_debug_logging_transport183--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)184=== CONT TestResolveStorePath185=== CONT TestDoWithRetry_BodyReplayedViaGetBody186=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths187=== CONT TestParsePathInfoJSON188=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess189=== RUN TestParsePathInfoJSON/Nix_format1902026/09/29 08:18:06 WARN Rate limiter enabled after throttle name=server-test rate=5191=== PAUSE TestParsePathInfoJSON/Nix_format192=== RUN TestParsePathInfoJSON/Lix_format193=== PAUSE TestParsePathInfoJSON/Lix_format194=== RUN TestParsePathInfoJSON/empty_input195=== PAUSE TestParsePathInfoJSON/empty_input196=== RUN TestParsePathInfoJSON/whitespace_only197=== PAUSE TestParsePathInfoJSON/whitespace_only198=== RUN TestParsePathInfoJSON/invalid_JSON199=== PAUSE TestParsePathInfoJSON/invalid_JSON200=== CONT TestRateLimiterFeedback201=== RUN TestRateLimiterFeedback/429_enables_limiter202=== PAUSE TestRateLimiterFeedback/429_enables_limiter203=== RUN TestRateLimiterFeedback/503_enables_limiter204=== PAUSE TestRateLimiterFeedback/503_enables_limiter205=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter206=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter207=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter208=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter209=== CONT TestUploadMultipart_SupersededByPeer210=== RUN TestUploadMultipart_SupersededByPeer/exists211=== PAUSE TestUploadMultipart_SupersededByPeer/exists212=== RUN TestUploadMultipart_SupersededByPeer/missing213=== PAUSE TestUploadMultipart_SupersededByPeer/missing214=== CONT TestEncodeNixBase32215=== RUN TestEncodeNixBase32/test_string_hash216=== PAUSE TestEncodeNixBase32/test_string_hash217=== RUN TestEncodeNixBase32/empty_input218=== PAUSE TestEncodeNixBase32/empty_input219=== CONT TestDumpPathWriterError220--- PASS: TestResolveStorePath (0.00s)221=== CONT TestDumpPathSingleFile2222026/09/29 08:18:06 WARN Rate limiter enabled after throttle name=server-test rate=52232026/09/29 08:18:06 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:565152242026/09/29 08:18:06 WARN Rate limiter backed off name=server-test rate=52252026/09/29 08:18:06 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56515226--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)227=== CONT TestDumpPathMatchesNix228--- PASS: TestScriptTokenBadJSON (0.01s)229=== CONT TestFilterOversizedClosures230=== RUN TestFilterOversizedClosures/no_limit_keeps_everything231=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything232=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped234=== RUN TestFilterOversizedClosures/all_closures_skipped235=== PAUSE TestFilterOversizedClosures/all_closures_skipped236=== CONT TestPartSizeForNAR237=== RUN TestPartSizeForNAR/zero_stays_at_minimum238=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum239=== RUN TestPartSizeForNAR/small_stays_at_minimum240=== PAUSE TestPartSizeForNAR/small_stays_at_minimum241=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum242=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum243=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts244=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts245=== RUN TestPartSizeForNAR/1_TiB246=== PAUSE TestPartSizeForNAR/1_TiB247=== RUN TestPartSizeForNAR/5_TiB_S3_max_object248=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object249=== RUN TestPartSizeForNAR/capped_at_5_GiB250=== PAUSE TestPartSizeForNAR/capped_at_5_GiB251=== CONT TestUploadMultipart_PartsInParallel252--- PASS: TestScriptTokenEmptyToken (0.02s)253=== CONT TestCaseHackSuffix254--- PASS: TestStreamPushRequestLine (0.01s)255=== CONT TestRegisterUploadedObjectReusesConnections256--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)257=== CONT TestPathInfoHashCompatibility258=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)259=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)260=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon261=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon262=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI263=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI264=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512265=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512266=== CONT TestPathInfoCACompatibility/null_ca_field267=== CONT TestSetClientTLSErrors/missing_cert_file268=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method269=== CONT TestPathInfoCACompatibility/new_structured_format_-_text270=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive271=== CONT TestPathInfoCACompatibility/old_string_format_-_text272=== CONT TestSetClientTLSErrors/missing_ca_file273=== CONT TestSetClientTLSErrors/missing_key_file274=== CONT TestGetStorePathHash/valid_store_path275=== CONT TestConvertHashToNix32/SRI_format_to_Nix32276=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error277--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)278=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error279=== CONT TestConvertHashToNix32/invalid_format280--- PASS: TestPathInfoCACompatibility (0.00s)281 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)282 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)283 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)284 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)285 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)286=== CONT TestSetClientTLSErrors/invalid_ca_file287--- PASS: TestSetClientTLSErrors (0.00s)288 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)289 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)290 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)291 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)292=== CONT TestConvertHashToNix32/already_Nix32_format293=== CONT TestGetStorePathHash/basename_without_hyphen_should_error294=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths295=== CONT TestSetClientTLS/preserves_debug_logging_transport296--- PASS: TestConvertHashToNix32 (0.00s)297 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)298 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)299 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)300--- PASS: TestGetStorePathHash (0.00s)301 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)302 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)303 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)304 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)305=== CONT TestSetClientTLS/rejects_connection_without_client_cert306=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA307--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)308=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths309--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)310 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)311 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)312=== CONT TestParsePathInfoJSON/Nix_format313=== CONT TestParsePathInfoJSON/whitespace_only314=== CONT TestParsePathInfoJSON/invalid_JSON315=== CONT TestParsePathInfoJSON/empty_input316=== CONT TestParsePathInfoJSON/Lix_format317=== CONT TestRateLimiterFeedback/429_enables_limiter318=== CONT TestUploadMultipart_SupersededByPeer/exists319--- PASS: TestParsePathInfoJSON (0.00s)320 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)321 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)322 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)323 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)324 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3252026/09/29 08:18:06 WARN Rate limiter enabled after throttle name=server-test rate=53262026/09/29 08:18:06 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:565923272026/09/29 08:18:06 WARN Rate limiter backed off name=server-test rate=5328=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter329=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter330=== CONT TestRateLimiterFeedback/503_enables_limiter331=== CONT TestUploadMultipart_SupersededByPeer/missing3322026/09/29 08:18:06 WARN Rate limiter enabled after throttle name=server-test rate=53332026/09/29 08:18:06 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:566003342026/09/29 08:18:06 WARN Rate limiter backed off name=server-test rate=5335--- PASS: TestRateLimiterFeedback (0.00s)336 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)337 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)338 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)339 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)340=== CONT TestEncodeNixBase32/test_string_hash341=== CONT TestEncodeNixBase32/empty_input342--- PASS: TestEncodeNixBase32 (0.00s)343 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)344 --- PASS: TestEncodeNixBase32/empty_input (0.00s)345=== CONT TestFilterOversizedClosures/no_limit_keeps_everything346=== CONT TestFilterOversizedClosures/all_closures_skipped3472026/09/29 08:18:06 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=50348=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3492026/09/29 08:18:06 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=2000350--- PASS: TestFilterOversizedClosures (0.00s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)353 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)354=== CONT TestPartSizeForNAR/zero_stays_at_minimum355=== CONT TestPartSizeForNAR/1_TiB356=== CONT TestPartSizeForNAR/capped_at_5_GiB357--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)358 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)359 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)360=== CONT TestPartSizeForNAR/5_TiB_S3_max_object361=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts362=== CONT TestPartSizeForNAR/small_stays_at_minimum363=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum364=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)365--- PASS: TestPartSizeForNAR (0.00s)366 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)368 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)369 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)370 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)371 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)372 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)373=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI374=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512375=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon376--- PASS: TestPathInfoHashCompatibility (0.00s)377 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)378 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)379 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)380 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)381--- PASS: TestDumpPathWriterError (0.05s)3822026/09/29 08:18:06 http: TLS handshake error from 127.0.0.1:56589: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.06s)388--- PASS: TestCaseHackSuffix (0.05s)389--- PASS: TestDumpPathMatchesNix (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld10".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-9673-972427610/postgres3287799747/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: 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.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-9673-972427610/postgres3287799747/data -l logfile start421422/nix/var/nix/builds/nix-9673-972427610/postgres3287799747:5432 - no response4232026-09-29 08:18:07.689 UTC [9907] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-29 08:18:07.689 UTC [9907] LOG: listening on Unix socket "/nix/var/nix/builds/nix-9673-972427610/postgres3287799747/.s.PGSQL.5432"4252026-09-29 08:18:07.693 UTC [9914] LOG: database system was shut down at 2026-09-29 08:18:07 UTC4262026-09-29 08:18:07.694 UTC [9907] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-9673-972427610/postgres3287799747:5432 - accepting connections428{"timestamp":"2026-09-29T08:18:07.905548Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"27fa61ff-6583-482a-8bbd-d4b62b47f453","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-09-29 08:18:08.128 UTC [9955] ERROR: relation "goose_db_version" does not exist at character 364712026-09-29 08:18:08.128 UTC [9955] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/09/29 08:18:08 OK 20241026095416_initial_model.sql (4.56ms)4732026/09/29 08:18:08 OK 20251210153512_drop_unused_gin_index.sql (999.96µs)4742026/09/29 08:18:08 OK 20251218171726_add_pins.sql (1.58ms)4752026/09/29 08:18:08 OK 20260628120000_add_object_size_and_stats.sql (2.08ms)4762026/09/29 08:18:08 OK 20260905000000_add_claims.sql (1.08ms)4772026/09/29 08:18:08 OK 20260920000000_drop_claims.sql (659.88µs)4782026/09/29 08:18:08 OK 20260923120000_add_pushes.sql (1.26ms)4792026/09/29 08:18:08 goose: successfully migrated database to version: 202609231200004802026/09/29 08:18:08 OK 1_commit_pending_closure.sql (1.52ms)4812026/09/29 08:18:08 OK 2_object_stats_trigger.sql (463.71µs)4822026/09/29 08:18:08 OK 3_commit_push.sql (341.5µs)4832026/09/29 08:18:08 goose: up to current file version: 34842026/09/29 08:18:08 INFO lead: acquired remote=192.0.2.1:12344852026/09/29 08:18:08 INFO lead: released remote=192.0.2.1:12344862026/09/29 08:18:08 INFO lead: acquired remote=192.0.2.1:12344872026/09/29 08:18:08 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.90s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-09-29 08:18:09.005 UTC [10146] ERROR: relation "goose_db_version" does not exist at character 364932026-09-29 08:18:09.005 UTC [10146] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/09/29 08:18:09 OK 20241026095416_initial_model.sql (7.16ms)4952026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (793.42µs)4962026/09/29 08:18:09 OK 20251218171726_add_pins.sql (1.08ms)4972026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (2.6ms)4982026/09/29 08:18:09 OK 20260905000000_add_claims.sql (1.24ms)4992026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (946.5µs)5002026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (1.32ms)5012026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200005022026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.74ms)5032026/09/29 08:18:09 OK 2_object_stats_trigger.sql (566.88µs)5042026/09/29 08:18:09 OK 3_commit_push.sql (515.29µs)5052026/09/29 08:18:09 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.26s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestGCTaskStore_StartNew512=== PAUSE TestGCTaskStore_StartNew513=== RUN TestGCTaskStore_DeduplicateSameParams514=== PAUSE TestGCTaskStore_DeduplicateSameParams515=== RUN TestGCTaskStore_ConflictDifferentParams516=== PAUSE TestGCTaskStore_ConflictDifferentParams517=== RUN TestGCTaskStore_GetEmpty518=== PAUSE TestGCTaskStore_GetEmpty519=== RUN TestGCTaskStore_GetReturnsLatest520=== PAUSE TestGCTaskStore_GetReturnsLatest521=== RUN TestGCTaskStore_CompletedAllowsNewTask522=== PAUSE TestGCTaskStore_CompletedAllowsNewTask523=== RUN TestGCTaskStore_PhaseUpdates524=== PAUSE TestGCTaskStore_PhaseUpdates525=== RUN TestGCTaskStore_Fail526=== PAUSE TestGCTaskStore_Fail527=== RUN TestGracefulShutdownDrainsInflight528=== PAUSE TestGracefulShutdownDrainsInflight529=== RUN TestService_healthCheckHandler530=== PAUSE TestService_healthCheckHandler531=== RUN TestService_readinessHandler532=== PAUSE TestService_readinessHandler533=== RUN TestGenerateLandingPage534=== PAUSE TestGenerateLandingPage535=== RUN TestCacheConfigHandlerMaxNarSize536=== PAUSE TestCacheConfigHandlerMaxNarSize537=== RUN TestCreatePendingClosureRejectsOversizedNAR538=== PAUSE TestCreatePendingClosureRejectsOversizedNAR539=== RUN TestNARDeduplicationMetadataUploadBug540=== PAUSE TestNARDeduplicationMetadataUploadBug541=== RUN TestMetricsInventory542=== PAUSE TestMetricsInventory543=== RUN TestService_NativeMTLS544=== PAUSE TestService_NativeMTLS545=== RUN TestServerTLSConfig546=== PAUSE TestServerTLSConfig547=== RUN TestMultipartCleanup548=== PAUSE TestMultipartCleanup549=== RUN TestObjectStatsTrigger550=== PAUSE TestObjectStatsTrigger551=== RUN TestOrphanedObjectsGC552=== PAUSE TestOrphanedObjectsGC553=== RUN TestOrphanedObjectsGCStressTest554=== PAUSE TestOrphanedObjectsGCStressTest555=== RUN TestResurrectedObjectNotDeleted556=== PAUSE TestResurrectedObjectNotDeleted557=== RUN TestCreatePin_ReservedPins558=== PAUSE TestCreatePin_ReservedPins559=== RUN TestParseSingleRange560=== PAUSE TestParseSingleRange561=== RUN TestProxyHeadersOnlyTrustedOnSocket562=== PAUSE TestProxyHeadersOnlyTrustedOnSocket563=== RUN TestIsValidCachePath564=== PAUSE TestIsValidCachePath565=== RUN TestReadProxyNarinfo566=== PAUSE TestReadProxyNarinfo567=== RUN TestReadProxyNarinfoAlreadyDecompressed568=== PAUSE TestReadProxyNarinfoAlreadyDecompressed569=== RUN TestReadProxyNarStreaming570=== PAUSE TestReadProxyNarStreaming571=== RUN TestReadProxy404572=== PAUSE TestReadProxy404573=== RUN TestReadProxyInvalidPath574=== PAUSE TestReadProxyInvalidPath575=== RUN TestReadProxyHead576=== PAUSE TestReadProxyHead577=== RUN TestReadProxyConditionalGet578=== PAUSE TestReadProxyConditionalGet579=== RUN TestReadProxyRootRedirectsToIndexHTML580=== PAUSE TestReadProxyRootRedirectsToIndexHTML581=== RUN TestReadProxyDisabled582=== PAUSE TestReadProxyDisabled583=== RUN TestReadRedirectNar584=== PAUSE TestReadRedirectNar585=== RUN TestReadRedirectKeepsNarinfoProxied586=== PAUSE TestReadRedirectKeepsNarinfoProxied587=== RUN TestReadProxyRangeRequest588=== PAUSE TestReadProxyRangeRequest589=== RUN TestReadRedirectUsesPublicS3URL590=== PAUSE TestReadRedirectUsesPublicS3URL591=== RUN TestPush_OverlappingRootsStoreOneRowPerKey592=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey593=== RUN TestPush_CompleteCommitsEveryRoot594=== PAUSE TestPush_CompleteCommitsEveryRoot595=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected596=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected597=== RUN TestPush_RejectsBadRequests598=== PAUSE TestPush_RejectsBadRequests599=== RUN TestPush_SignsNarinfosOfItsPendingObjects600=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects601=== RUN TestRedundantMultipartUpload602=== PAUSE TestRedundantMultipartUpload603=== RUN TestCompleteMultipartUpload_ErrorButObjectExists604=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists605=== RUN TestCompletedNarNotReofferedAcrossClosures606=== PAUSE TestCompletedNarNotReofferedAcrossClosures607=== RUN TestPresignedUploadRegisteredBeforeCommit608=== PAUSE TestPresignedUploadRegisteredBeforeCommit609=== RUN TestService_Rustfstest610=== PAUSE TestService_Rustfstest611=== RUN TestParseSize612=== PAUSE TestParseSize613=== RUN TestSkippedUploadsHandler614=== PAUSE TestSkippedUploadsHandler615=== RUN TestSystemdListenerNotActivated616--- PASS: TestSystemdListenerNotActivated (0.00s)617=== RUN TestWatchdogBeatsWhenHealthy618--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)619=== RUN TestWatchdogSkipsWhenUnhealthy6202026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/29 08:18:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"630--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)631=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== RUN TestProxyWriteTimeout634=== PAUSE TestProxyWriteTimeout635=== RUN TestIsValidUploadKey636=== PAUSE TestIsValidUploadKey637=== RUN TestUploadHandlersRejectInvalidKeys638=== PAUSE TestUploadHandlersRejectInvalidKeys639=== RUN TestUploadHandlersRejectOversizedBody640=== PAUSE TestUploadHandlersRejectOversizedBody641=== RUN TestService_cleanupPendingClosuresHandler642=== PAUSE TestService_cleanupPendingClosuresHandler643=== RUN TestService_createPendingClosureHandler644=== PAUSE TestService_createPendingClosureHandler645=== RUN TestService_verifyS3Integrity646=== PAUSE TestService_verifyS3Integrity647=== RUN TestCompleteMultipartUnregistered648=== PAUSE TestCompleteMultipartUnregistered649=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT650=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT651=== CONT TestService_AuthMiddleware652=== CONT TestOrphanedObjectsGC653=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT654=== CONT TestCompleteMultipartUnregistered655=== CONT TestService_verifyS3Integrity656=== CONT TestReadRedirectUsesPublicS3URL657=== CONT TestPush_OverlappingRootsStoreOneRowPerKey658=== CONT TestParseSize659--- PASS: TestParseSize (0.00s)660=== CONT TestService_createPendingClosureHandler661=== CONT TestRedundantMultipartUpload662=== CONT TestService_Rustfstest6632026-09-29 08:18:09.620 UTC [10308] ERROR: relation "goose_db_version" does not exist at character 366642026-09-29 08:18:09.620 UTC [10308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026/09/29 08:18:09 OK 20241026095416_initial_model.sql (3.94ms)6662026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)6672026-09-29 08:18:09.632 UTC [10310] ERROR: relation "goose_db_version" does not exist at character 366682026-09-29 08:18:09.632 UTC [10310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6692026/09/29 08:18:09 OK 20251218171726_add_pins.sql (3.19ms)6702026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)6712026/09/29 08:18:09 OK 20260905000000_add_claims.sql (8.93ms)6722026-09-29 08:18:09.655 UTC [10312] ERROR: relation "goose_db_version" does not exist at character 366732026-09-29 08:18:09.655 UTC [10312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6742026/09/29 08:18:09 OK 20241026095416_initial_model.sql (12.75ms)6752026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (8.76ms)6762026-09-29 08:18:09.657 UTC [10313] ERROR: relation "goose_db_version" does not exist at character 366772026-09-29 08:18:09.657 UTC [10313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6782026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)6792026-09-29 08:18:09.660 UTC [10315] ERROR: relation "goose_db_version" does not exist at character 366802026-09-29 08:18:09.660 UTC [10315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026-09-29 08:18:09.660 UTC [10314] ERROR: relation "goose_db_version" does not exist at character 366822026-09-29 08:18:09.660 UTC [10314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6832026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (3.29ms)6842026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200006852026/09/29 08:18:09 OK 20251218171726_add_pins.sql (3.07ms)6862026/09/29 08:18:09 OK 1_commit_pending_closure.sql (2.55ms)6872026-09-29 08:18:09.664 UTC [10316] ERROR: relation "goose_db_version" does not exist at character 366882026-09-29 08:18:09.664 UTC [10316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6892026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (2.31ms)6902026/09/29 08:18:09 OK 2_object_stats_trigger.sql (1.34ms)6912026-09-29 08:18:09.666 UTC [10317] ERROR: relation "goose_db_version" does not exist at character 366922026-09-29 08:18:09.666 UTC [10317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6932026/09/29 08:18:09 OK 3_commit_push.sql (1.09ms)6942026/09/29 08:18:09 goose: up to current file version: 36952026/09/29 08:18:09 OK 20260905000000_add_claims.sql (2.82ms)6962026-09-29 08:18:09.668 UTC [10318] ERROR: relation "goose_db_version" does not exist at character 366972026-09-29 08:18:09.668 UTC [10318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6982026/09/29 08:18:09 OK 20241026095416_initial_model.sql (8.2ms)6992026-09-29 08:18:09.670 UTC [10319] ERROR: relation "goose_db_version" does not exist at character 367002026-09-29 08:18:09.670 UTC [10319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7012026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (1.91ms)7022026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (850.92µs)7032026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (11.22ms)7042026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007052026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.87ms)7062026/09/29 08:18:09 OK 2_object_stats_trigger.sql (510.54µs)7072026/09/29 08:18:09 OK 3_commit_push.sql (386.96µs)7082026/09/29 08:18:09 goose: up to current file version: 37092026/09/29 08:18:09 OK 20241026095416_initial_model.sql (81.77ms)7102026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (8.29ms)7112026/09/29 08:18:09 OK 20251218171726_add_pins.sql (86.22ms)7122026/09/29 08:18:09 OK 20241026095416_initial_model.sql (91.23ms)7132026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (8.59ms)7142026/09/29 08:18:09 OK 20251218171726_add_pins.sql (12.28ms)7152026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (10.54ms)7162026/09/29 08:18:09 OK 20241026095416_initial_model.sql (109.28ms)7172026/09/29 08:18:09 OK 20251218171726_add_pins.sql (10.34ms)7182026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (10.79ms)7192026/09/29 08:18:09 OK 20260905000000_add_claims.sql (11.35ms)7202026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)7212026/09/29 08:18:09 OK 20241026095416_initial_model.sql (110.36ms)7222026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)7232026/09/29 08:18:09 OK 20241026095416_initial_model.sql (109.35ms)7242026/09/29 08:18:09 OK 20241026095416_initial_model.sql (25.6ms)7252026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)7262026/09/29 08:18:09 OK 20251218171726_add_pins.sql (4.08ms)7272026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (4.15ms)7282026/09/29 08:18:09 OK 20260905000000_add_claims.sql (5.9ms)7292026/09/29 08:18:09 OK 20260905000000_add_claims.sql (3.51ms)7302026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (5.11ms)7312026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)7322026/09/29 08:18:09 OK 20241026095416_initial_model.sql (28.34ms)7332026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (10.12ms)7342026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007352026/09/29 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (7.69ms)7362026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (11.31ms)7372026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (11.35ms)7382026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.87ms)7392026/09/29 08:18:09 OK 20251218171726_add_pins.sql (12.42ms)7402026/09/29 08:18:09 OK 2_object_stats_trigger.sql (499.58µs)7412026/09/29 08:18:09 OK 3_commit_push.sql (439.46µs)7422026/09/29 08:18:09 goose: up to current file version: 37432026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (21.54ms)7442026/09/29 08:18:09 OK 20251218171726_add_pins.sql (18.82ms)7452026/09/29 08:18:09 OK 20251218171726_add_pins.sql (10.24ms)7462026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (9.8ms)7472026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007482026/09/29 08:18:09 OK 20251218171726_add_pins.sql (18.95ms)7492026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (9.97ms)7502026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007512026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.41ms)7522026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (10.82ms)7532026/09/29 08:18:09 OK 2_object_stats_trigger.sql (413.79µs)7542026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.81ms)7552026/09/29 08:18:09 OK 3_commit_push.sql (400.58µs)7562026/09/29 08:18:09 goose: up to current file version: 37572026/09/29 08:18:09 OK 2_object_stats_trigger.sql (495.17µs)7582026/09/29 08:18:09 OK 3_commit_push.sql (416.83µs)7592026/09/29 08:18:09 goose: up to current file version: 37602026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (10.09ms)7612026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (15.55ms)7622026/09/29 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (15.71ms)7632026/09/29 08:18:09 OK 20260905000000_add_claims.sql (15.81ms)7642026/09/29 08:18:09 OK 20260905000000_add_claims.sql (7.41ms)7652026/09/29 08:18:09 OK 20260905000000_add_claims.sql (16.1ms)7662026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (3.36ms)7672026/09/29 08:18:09 OK 20260905000000_add_claims.sql (3.52ms)7682026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (7.51ms)7692026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (10.02ms)7702026/09/29 08:18:09 OK 20260905000000_add_claims.sql (12.24ms)7712026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (8.9ms)7722026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007732026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.79ms)7742026/09/29 08:18:09 OK 2_object_stats_trigger.sql (556.54µs)7752026/09/29 08:18:09 OK 3_commit_push.sql (559.79µs)7762026/09/29 08:18:09 goose: up to current file version: 37772026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (8.72ms)7782026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007792026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (8.13ms)7802026/09/29 08:18:09 OK 20260920000000_drop_claims.sql (18.44ms)7812026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (9.63ms)7822026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007832026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.95ms)7842026/09/29 08:18:09 OK 2_object_stats_trigger.sql (622.42µs)7852026/09/29 08:18:09 OK 3_commit_push.sql (455.42µs)7862026/09/29 08:18:09 goose: up to current file version: 37872026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.85ms)7882026/09/29 08:18:09 OK 2_object_stats_trigger.sql (489.46µs)7892026/09/29 08:18:09 OK 3_commit_push.sql (399µs)7902026/09/29 08:18:09 goose: up to current file version: 37912026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (8.47ms)7922026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007932026/09/29 08:18:09 OK 20260923120000_add_pushes.sql (8.53ms)7942026/09/29 08:18:09 goose: successfully migrated database to version: 202609231200007952026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.52ms)7962026/09/29 08:18:09 OK 1_commit_pending_closure.sql (1.81ms)7972026/09/29 08:18:09 OK 2_object_stats_trigger.sql (1.22ms)7982026/09/29 08:18:09 OK 2_object_stats_trigger.sql (1.24ms)7992026/09/29 08:18:09 OK 3_commit_push.sql (576.67µs)8002026/09/29 08:18:09 goose: up to current file version: 38012026/09/29 08:18:09 OK 3_commit_push.sql (344.33µs)8022026/09/29 08:18:09 goose: up to current file version: 38032026/09/29 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures804--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)805=== CONT TestReadProxyNarStreaming8062026/09/29 08:18:10 INFO Received uploads request method=POST path=/api/pending_closures8072026/09/29 08:18:10 INFO Received uploads request method=POST path=/api/pending_closures8082026/09/29 08:18:10 INFO Received uploads request method=POST path=/api/pending_closures809--- PASS: TestReadRedirectUsesPublicS3URL (0.89s)810=== CONT TestReadProxyNarinfoAlreadyDecompressed8112026/09/29 08:18:10 INFO Received push request method=POST path=/api/pushes812--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.20s)813=== CONT TestReadProxyNarinfo8142026-09-29 08:18:10.610 UTC [10361] ERROR: relation "goose_db_version" does not exist at character 368152026-09-29 08:18:10.610 UTC [10361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/09/29 08:18:10 OK 20241026095416_initial_model.sql (54.44ms)8172026/09/29 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (11.34ms)8182026/09/29 08:18:10 OK 20251218171726_add_pins.sql (15.12ms)8192026/09/29 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (13.21ms)8202026/09/29 08:18:10 OK 20260905000000_add_claims.sql (11.55ms)8212026/09/29 08:18:10 OK 20260920000000_drop_claims.sql (23.97ms)8222026/09/29 08:18:10 OK 20260923120000_add_pushes.sql (3.01ms)8232026/09/29 08:18:10 goose: successfully migrated database to version: 202609231200008242026/09/29 08:18:10 OK 1_commit_pending_closure.sql (2.48ms)8252026-09-29 08:18:10.755 UTC [10383] ERROR: relation "goose_db_version" does not exist at character 368262026-09-29 08:18:10.755 UTC [10383] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8272026/09/29 08:18:10 OK 2_object_stats_trigger.sql (932.29µs)8282026/09/29 08:18:10 OK 3_commit_push.sql (899.08µs)8292026/09/29 08:18:10 goose: up to current file version: 38302026/09/29 08:18:10 OK 20241026095416_initial_model.sql (27.01ms)8312026/09/29 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)8322026/09/29 08:18:10 OK 20251218171726_add_pins.sql (8.34ms)8332026/09/29 08:18:10 INFO Received uploads request method=POST path=/api/pending_closures8342026/09/29 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (20.83ms)8352026/09/29 08:18:10 OK 20260905000000_add_claims.sql (26.16ms)8362026/09/29 08:18:10 OK 20260920000000_drop_claims.sql (38.89ms)8372026/09/29 08:18:10 INFO Received uploads request method=POST path=/api/pending_closures8382026/09/29 08:18:10 OK 20260923120000_add_pushes.sql (15.18ms)8392026/09/29 08:18:10 goose: successfully migrated database to version: 202609231200008402026/09/29 08:18:10 OK 1_commit_pending_closure.sql (1.12ms)8412026/09/29 08:18:10 OK 2_object_stats_trigger.sql (271.75µs)8422026/09/29 08:18:10 OK 3_commit_push.sql (228.25µs)8432026/09/29 08:18:10 goose: up to current file version: 38442026-09-29 08:18:10.925 UTC [10392] ERROR: relation "goose_db_version" does not exist at character 368452026-09-29 08:18:10.925 UTC [10392] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8462026/09/29 08:18:11 OK 20241026095416_initial_model.sql (76.32ms)8472026/09/29 08:18:11 OK 20251210153512_drop_unused_gin_index.sql (18.06ms)8482026/09/29 08:18:11 OK 20251218171726_add_pins.sql (16.42ms)849--- PASS: TestService_Rustfstest (1.70s)850=== CONT TestIsValidCachePath851=== RUN TestIsValidCachePath/narinfo852=== PAUSE TestIsValidCachePath/narinfo853=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars854=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars855=== RUN TestIsValidCachePath/nar_zst856=== PAUSE TestIsValidCachePath/nar_zst857=== RUN TestIsValidCachePath/nar_xz858=== PAUSE TestIsValidCachePath/nar_xz859=== RUN TestIsValidCachePath/nar_bz2860=== PAUSE TestIsValidCachePath/nar_bz2861=== RUN TestIsValidCachePath/nar_uncompressed862=== PAUSE TestIsValidCachePath/nar_uncompressed863=== RUN TestIsValidCachePath/ls864=== PAUSE TestIsValidCachePath/ls865=== RUN TestIsValidCachePath/log866=== PAUSE TestIsValidCachePath/log867=== RUN TestIsValidCachePath/realisation868=== PAUSE TestIsValidCachePath/realisation869=== RUN TestIsValidCachePath/nix-cache-info870=== PAUSE TestIsValidCachePath/nix-cache-info871=== RUN TestIsValidCachePath/index.html872=== PAUSE TestIsValidCachePath/index.html873=== RUN TestIsValidCachePath/traversal_parent874=== PAUSE TestIsValidCachePath/traversal_parent875=== RUN TestIsValidCachePath/traversal_in_middle876=== PAUSE TestIsValidCachePath/traversal_in_middle877=== RUN TestIsValidCachePath/invalid_char_e878=== PAUSE TestIsValidCachePath/invalid_char_e879=== RUN TestIsValidCachePath/invalid_char_u880=== PAUSE TestIsValidCachePath/invalid_char_u881=== RUN TestIsValidCachePath/random_path882=== PAUSE TestIsValidCachePath/random_path883=== RUN TestIsValidCachePath/empty884=== PAUSE TestIsValidCachePath/empty885=== RUN TestIsValidCachePath/leading_slash886=== PAUSE TestIsValidCachePath/leading_slash887=== RUN TestIsValidCachePath/wrong_extension888=== PAUSE TestIsValidCachePath/wrong_extension889=== RUN TestIsValidCachePath/short_hash890=== PAUSE TestIsValidCachePath/short_hash891=== CONT TestProxyHeadersOnlyTrustedOnSocket8922026/09/29 08:18:11 OK 20260628120000_add_object_size_and_stats.sql (28.16ms)8932026/09/29 08:18:11 OK 20260905000000_add_claims.sql (58.22ms)8942026/09/29 08:18:11 OK 20260920000000_drop_claims.sql (13.87ms)8952026/09/29 08:18:11 OK 20260923120000_add_pushes.sql (11ms)8962026/09/29 08:18:11 goose: successfully migrated database to version: 202609231200008972026/09/29 08:18:11 OK 1_commit_pending_closure.sql (1.95ms)8982026/09/29 08:18:11 OK 2_object_stats_trigger.sql (549.33µs)8992026/09/29 08:18:11 OK 3_commit_push.sql (473.42µs)9002026/09/29 08:18:11 goose: up to current file version: 39012026/09/29 08:18:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9022026/09/29 08:18:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Mzg0NjRiY2ItZmUwNy00N2Q4LThjMWEtZjIwNTg1MjkxOTIyLjI5MGIyZjkyLWI4MWQtNGZmZS1iN2E0LTc3ZThmYTFkZDAwY3gxNzkwNjY5ODkwMDgyOTQ5MDAw parts=109032026/09/29 08:18:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9042026/09/29 08:18:11 INFO Completed upload id=19052026/09/29 08:18:11 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009062026/09/29 08:18:11 INFO Received uploads request method=POST path=/api/pending_closures9072026/09/29 08:18:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures9082026/09/29 08:18:11 INFO Aborted multipart uploads count=09092026/09/29 08:18:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=09102026/09/29 08:18:11 INFO Vacuumed table table=pending_closures9112026/09/29 08:18:11 INFO Vacuumed table table=pending_objects9122026/09/29 08:18:11 INFO Vacuumed table table=multipart_uploads9132026/09/29 08:18:11 INFO Vacuumed table table=closures9142026/09/29 08:18:11 INFO Vacuumed table table=objects9152026/09/29 08:18:11 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000916--- PASS: TestService_createPendingClosureHandler (2.13s)917=== CONT TestParseSingleRange918=== RUN TestParseSingleRange/none919=== PAUSE TestParseSingleRange/none920=== RUN TestParseSingleRange/unknown_unit921=== PAUSE TestParseSingleRange/unknown_unit922=== RUN TestParseSingleRange/multi-range_ignored923=== PAUSE TestParseSingleRange/multi-range_ignored924=== RUN TestParseSingleRange/malformed_no_dash925=== PAUSE TestParseSingleRange/malformed_no_dash926=== RUN TestParseSingleRange/malformed_both_empty927=== PAUSE TestParseSingleRange/malformed_both_empty928=== RUN TestParseSingleRange/malformed_end_before_start929=== PAUSE TestParseSingleRange/malformed_end_before_start930=== RUN TestParseSingleRange/closed931=== PAUSE TestParseSingleRange/closed932=== RUN TestParseSingleRange/open-ended933=== PAUSE TestParseSingleRange/open-ended934=== RUN TestParseSingleRange/end_clamped_to_size935=== PAUSE TestParseSingleRange/end_clamped_to_size936=== RUN TestParseSingleRange/suffix937=== PAUSE TestParseSingleRange/suffix938=== RUN TestParseSingleRange/suffix_exceeds_size939=== PAUSE TestParseSingleRange/suffix_exceeds_size940=== RUN TestParseSingleRange/single_byte941=== PAUSE TestParseSingleRange/single_byte942=== RUN TestParseSingleRange/start_past_EOF943=== PAUSE TestParseSingleRange/start_past_EOF944=== RUN TestParseSingleRange/start_far_past_EOF945=== PAUSE TestParseSingleRange/start_far_past_EOF946=== CONT TestCreatePin_ReservedPins9472026/09/29 08:18:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56632/oidc9482026/09/29 08:18:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9492026/09/29 08:18:11 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst950--- PASS: TestCompleteMultipartUnregistered (2.25s)951=== CONT TestResurrectedObjectNotDeleted9522026/09/29 08:18:11 INFO Received uploads request method=POST path=/api/pending_closures9532026-09-29 08:18:12.022 UTC [10463] ERROR: relation "goose_db_version" does not exist at character 369542026-09-29 08:18:12.022 UTC [10463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC955=== NAME TestOrphanedObjectsGC956 orphaned_objects_gc_test.go:290: GC Test Summary:957 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A958 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B959 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)960 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)961 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects962--- PASS: TestOrphanedObjectsGC (2.76s)963=== CONT TestOrphanedObjectsGCStressTest9642026/09/29 08:18:12 OK 20241026095416_initial_model.sql (117.67ms)9652026/09/29 08:18:12 OK 20251210153512_drop_unused_gin_index.sql (11.96ms)9662026/09/29 08:18:12 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"967--- PASS: TestService_AuthMiddleware (2.89s)9682026/09/29 08:18:12 OK 20251218171726_add_pins.sql (32.42ms)969=== CONT TestIsValidUploadKey970=== RUN TestIsValidUploadKey/narinfo971=== PAUSE TestIsValidUploadKey/narinfo972=== RUN TestIsValidUploadKey/nar_zst973=== PAUSE TestIsValidUploadKey/nar_zst974=== RUN TestIsValidUploadKey/nar_xz975=== PAUSE TestIsValidUploadKey/nar_xz976=== RUN TestIsValidUploadKey/nar_plain977=== PAUSE TestIsValidUploadKey/nar_plain978=== RUN TestIsValidUploadKey/listing979=== PAUSE TestIsValidUploadKey/listing980=== RUN TestIsValidUploadKey/build_log981=== PAUSE TestIsValidUploadKey/build_log982=== RUN TestIsValidUploadKey/build_log_home-manager_file983=== PAUSE TestIsValidUploadKey/build_log_home-manager_file984=== RUN TestIsValidUploadKey/build_log_plus_in_name985=== PAUSE TestIsValidUploadKey/build_log_plus_in_name986=== RUN TestIsValidUploadKey/build_log_question_mark987=== PAUSE TestIsValidUploadKey/build_log_question_mark988=== RUN TestIsValidUploadKey/build_log_equals989=== PAUSE TestIsValidUploadKey/build_log_equals990=== RUN TestIsValidUploadKey/realisation991=== PAUSE TestIsValidUploadKey/realisation992=== RUN TestIsValidUploadKey/realisation_plus_in_output993=== PAUSE TestIsValidUploadKey/realisation_plus_in_output994=== RUN TestIsValidUploadKey/nix-cache-info995=== PAUSE TestIsValidUploadKey/nix-cache-info996=== RUN TestIsValidUploadKey/index.html997=== PAUSE TestIsValidUploadKey/index.html998=== RUN TestIsValidUploadKey/narinfo_key,_nar_type999=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1000=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1001=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1002=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1003=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1004=== RUN TestIsValidUploadKey/traversal1005=== PAUSE TestIsValidUploadKey/traversal1006=== RUN TestIsValidUploadKey/traversal_nar1007=== PAUSE TestIsValidUploadKey/traversal_nar1008=== RUN TestIsValidUploadKey/absolute1009=== PAUSE TestIsValidUploadKey/absolute1010=== RUN TestIsValidUploadKey/empty_key1011=== PAUSE TestIsValidUploadKey/empty_key1012=== RUN TestIsValidUploadKey/unknown_type1013=== PAUSE TestIsValidUploadKey/unknown_type1014=== CONT TestService_cleanupPendingClosuresHandler10152026/09/29 08:18:12 OK 20260628120000_add_object_size_and_stats.sql (37.88ms)10162026/09/29 08:18:12 OK 20260905000000_add_claims.sql (72.14ms)10172026/09/29 08:18:12 OK 20260920000000_drop_claims.sql (32.17ms)10182026/09/29 08:18:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10192026/09/29 08:18:12 OK 20260923120000_add_pushes.sql (23.5ms)10202026/09/29 08:18:12 goose: successfully migrated database to version: 2026092312000010212026/09/29 08:18:12 OK 1_commit_pending_closure.sql (1.94ms)10222026/09/29 08:18:12 OK 2_object_stats_trigger.sql (548.25µs)10232026/09/29 08:18:12 OK 3_commit_push.sql (467.5µs)10242026/09/29 08:18:12 goose: up to current file version: 310252026/09/29 08:18:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Mzg0NjRiY2ItZmUwNy00N2Q4LThjMWEtZjIwNTg1MjkxOTIyLmY0ODE0YWMzLTkwYmQtNDRiOS1iMGU5LTlhMzc5YzU2NDE4NngxNzkwNjY5ODkwODM3OTQ5MDAw parts=121026--- PASS: TestRedundantMultipartUpload (3.10s)1027=== CONT TestUploadHandlersRejectOversizedBody1028=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1029=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1030=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1031=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1032=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1033=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1034=== CONT TestUploadHandlersRejectInvalidKeys1035=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1036=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1037=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1038=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1039=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1040=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1041=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1042=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1043=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1044--- PASS: TestReadProxyNarStreaming (2.64s)1045=== CONT TestProxyWriteTimeout1046=== RUN TestProxyWriteTimeout/narinfo1047=== PAUSE TestProxyWriteTimeout/narinfo1048=== RUN TestProxyWriteTimeout/1_GiB_nar1049=== PAUSE TestProxyWriteTimeout/1_GiB_nar1050=== RUN TestProxyWriteTimeout/10_GiB_nar1051=== PAUSE TestProxyWriteTimeout/10_GiB_nar1052=== RUN TestProxyWriteTimeout/unknown_size1053=== PAUSE TestProxyWriteTimeout/unknown_size1054=== CONT TestGCMetrics1055--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.57s)1056=== CONT TestObjectStatsTrigger1057--- PASS: TestReadProxyNarinfo (2.48s)1058=== CONT TestMultipartCleanup10592026-09-29 08:18:13.229 UTC [10511] ERROR: relation "goose_db_version" does not exist at character 3610602026-09-29 08:18:13.229 UTC [10511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10612026-09-29 08:18:13.229 UTC [10512] ERROR: relation "goose_db_version" does not exist at character 3610622026-09-29 08:18:13.229 UTC [10512] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10632026/09/29 08:18:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10642026/09/29 08:18:13 OK 20241026095416_initial_model.sql (86.8ms)10652026/09/29 08:18:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Mzg0NjRiY2ItZmUwNy00N2Q4LThjMWEtZjIwNTg1MjkxOTIyLmFhOWE5MTQ4LTVmMDYtNGQ5OC05ODY4LTBkZmMzNGU4ODZkZHgxNzkwNjY5ODkxOTU2NDc4MDAw parts=1010662026/09/29 08:18:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10672026/09/29 08:18:13 INFO Starting HTTP server address=127.0.0.1:5665010682026/09/29 08:18:13 INFO Starting HTTP server address=/nix/var/nix/builds/nix-9673-972427610/TestProxyHeadersOnlyTrustedOnSocket1939090309/001/proxy.sock10692026/09/29 08:18:13 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10702026/09/29 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (15.61ms)10712026/09/29 08:18:13 INFO Shutdown signal received, draining in-flight requests timeout=10s10722026/09/29 08:18:13 INFO Completed upload id=110732026/09/29 08:18:13 INFO Received uploads request method=POST path=/api/pending_closures10742026/09/29 08:18:13 INFO Received uploads request method=POST path=/api/pending_closures10752026/09/29 08:18:13 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10762026/09/29 08:18:13 WARN Found objects in DB but missing from S3, will re-upload count=11077--- PASS: TestService_verifyS3Integrity (3.99s)1078=== CONT TestServerTLSConfig1079=== RUN TestServerTLSConfig/no_client_CA1080=== PAUSE TestServerTLSConfig/no_client_CA1081=== RUN TestServerTLSConfig/missing_CA_file1082=== PAUSE TestServerTLSConfig/missing_CA_file1083=== RUN TestServerTLSConfig/not_a_PEM_file1084=== PAUSE TestServerTLSConfig/not_a_PEM_file1085=== CONT TestService_NativeMTLS1086--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.30s)1087=== CONT TestMetricsInventory10882026/09/29 08:18:13 OK 20251218171726_add_pins.sql (14.86ms)10892026/09/29 08:18:13 OK 20241026095416_initial_model.sql (151.28ms)10902026/09/29 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (19.68ms)10912026/09/29 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (10.5ms)10922026/09/29 08:18:13 OK 20251218171726_add_pins.sql (15.36ms)10932026/09/29 08:18:13 OK 20260905000000_add_claims.sql (30.7ms)10942026/09/29 08:18:13 OK 20260920000000_drop_claims.sql (1.21ms)10952026/09/29 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (9.8ms)10962026/09/29 08:18:13 OK 20260923120000_add_pushes.sql (1.98ms)10972026/09/29 08:18:13 goose: successfully migrated database to version: 2026092312000010982026/09/29 08:18:13 OK 1_commit_pending_closure.sql (2.54ms)10992026/09/29 08:18:13 OK 2_object_stats_trigger.sql (510.92µs)11002026/09/29 08:18:13 OK 3_commit_push.sql (398.17µs)11012026/09/29 08:18:13 goose: up to current file version: 311022026/09/29 08:18:13 OK 20260905000000_add_claims.sql (5.07ms)11032026-09-29 08:18:13.467 UTC [10523] ERROR: relation "goose_db_version" does not exist at character 3611042026-09-29 08:18:13.467 UTC [10523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/09/29 08:18:13 OK 20260920000000_drop_claims.sql (3.27ms)11062026/09/29 08:18:13 OK 20260923120000_add_pushes.sql (769.13µs)11072026/09/29 08:18:13 goose: successfully migrated database to version: 2026092312000011082026/09/29 08:18:13 OK 1_commit_pending_closure.sql (1.54ms)11092026/09/29 08:18:13 OK 2_object_stats_trigger.sql (489.71µs)11102026/09/29 08:18:13 OK 3_commit_push.sql (385.71µs)11112026/09/29 08:18:13 goose: up to current file version: 311122026-09-29 08:18:13.537 UTC [10524] ERROR: relation "goose_db_version" does not exist at character 3611132026-09-29 08:18:13.537 UTC [10524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11142026/09/29 08:18:13 OK 20241026095416_initial_model.sql (65.93ms)11152026/09/29 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)11162026/09/29 08:18:13 OK 20251218171726_add_pins.sql (14.66ms)11172026/09/29 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (22.06ms)11182026/09/29 08:18:13 OK 20260905000000_add_claims.sql (16.44ms)11192026/09/29 08:18:13 OK 20260920000000_drop_claims.sql (32.82ms)11202026/09/29 08:18:13 OK 20241026095416_initial_model.sql (89.65ms)11212026/09/29 08:18:13 OK 20260923120000_add_pushes.sql (7.71ms)11222026/09/29 08:18:13 goose: successfully migrated database to version: 2026092312000011232026/09/29 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (7.25ms)11242026/09/29 08:18:13 OK 1_commit_pending_closure.sql (6.82ms)11252026/09/29 08:18:13 OK 2_object_stats_trigger.sql (1.76ms)11262026-09-29 08:18:13.675 UTC [10526] ERROR: relation "goose_db_version" does not exist at character 3611272026-09-29 08:18:13.675 UTC [10526] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11282026/09/29 08:18:13 OK 3_commit_push.sql (5.21ms)11292026/09/29 08:18:13 goose: up to current file version: 311302026/09/29 08:18:13 OK 20251218171726_add_pins.sql (12.09ms)11312026/09/29 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (43.31ms)11322026/09/29 08:18:13 OK 20260905000000_add_claims.sql (26.5ms)11332026/09/29 08:18:13 OK 20260920000000_drop_claims.sql (30.67ms)11342026-09-29 08:18:13.778 UTC [10529] ERROR: relation "goose_db_version" does not exist at character 3611352026-09-29 08:18:13.778 UTC [10529] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11362026/09/29 08:18:13 OK 20260923120000_add_pushes.sql (19.19ms)11372026/09/29 08:18:13 goose: successfully migrated database to version: 2026092312000011382026/09/29 08:18:13 OK 1_commit_pending_closure.sql (1.93ms)11392026/09/29 08:18:13 OK 2_object_stats_trigger.sql (579.04µs)11402026/09/29 08:18:13 OK 3_commit_push.sql (415.42µs)11412026/09/29 08:18:13 goose: up to current file version: 31142--- PASS: TestResurrectedObjectNotDeleted (2.15s)1143=== CONT TestNARDeduplicationMetadataUploadBug11442026/09/29 08:18:13 OK 20241026095416_initial_model.sql (128.47ms)11452026/09/29 08:18:13 OK 20241026095416_initial_model.sql (50.11ms)11462026/09/29 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (14.96ms)11472026/09/29 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (9.4ms)11482026/09/29 08:18:13 OK 20251218171726_add_pins.sql (15.46ms)11492026/09/29 08:18:13 OK 20251218171726_add_pins.sql (7.24ms)11502026/09/29 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (20.62ms)11512026/09/29 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (22.51ms)11522026/09/29 08:18:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11532026/09/29 08:18:13 WARN Refused reserved pin name=worker-x86_64-linux11542026/09/29 08:18:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11552026/09/29 08:18:13 INFO Received create pin request method=POST path=/api/pins/my-app11562026/09/29 08:18:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1157--- PASS: TestCreatePin_ReservedPins (2.40s)1158=== CONT TestCreatePendingClosureRejectsOversizedNAR11592026/09/29 08:18:13 INFO Received uploads request method=POST path=/api/pending_closures1160--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1161=== CONT TestCacheConfigHandlerMaxNarSize1162--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1163=== CONT TestGenerateLandingPage11642026/09/29 08:18:13 OK 20260905000000_add_claims.sql (21.87ms)1165--- PASS: TestGenerateLandingPage (0.00s)1166=== CONT TestService_readinessHandler11672026/09/29 08:18:13 OK 20260905000000_add_claims.sql (39.5ms)11682026/09/29 08:18:13 OK 20260920000000_drop_claims.sql (32.53ms)11692026/09/29 08:18:13 OK 20260920000000_drop_claims.sql (22.03ms)11702026/09/29 08:18:13 OK 20260923120000_add_pushes.sql (15.66ms)11712026/09/29 08:18:13 goose: successfully migrated database to version: 2026092312000011722026/09/29 08:18:13 OK 20260923120000_add_pushes.sql (9.62ms)11732026/09/29 08:18:13 goose: successfully migrated database to version: 2026092312000011742026/09/29 08:18:13 OK 1_commit_pending_closure.sql (2.85ms)11752026/09/29 08:18:13 OK 2_object_stats_trigger.sql (626.96µs)11762026/09/29 08:18:13 OK 3_commit_push.sql (431.92µs)11772026/09/29 08:18:13 goose: up to current file version: 311782026/09/29 08:18:13 OK 1_commit_pending_closure.sql (1.96ms)11792026/09/29 08:18:13 OK 2_object_stats_trigger.sql (503.79µs)11802026/09/29 08:18:13 OK 3_commit_push.sql (488.13µs)11812026/09/29 08:18:13 goose: up to current file version: 311822026-09-29 08:18:14.024 UTC [10535] ERROR: relation "goose_db_version" does not exist at character 3611832026-09-29 08:18:14.024 UTC [10535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11842026/09/29 08:18:14 OK 20241026095416_initial_model.sql (94.52ms)11852026/09/29 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (8.4ms)11862026/09/29 08:18:14 OK 20251218171726_add_pins.sql (51.74ms)11872026/09/29 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (23.01ms)11882026-09-29 08:18:14.250 UTC [10536] ERROR: relation "goose_db_version" does not exist at character 3611892026-09-29 08:18:14.250 UTC [10536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11902026/09/29 08:18:14 OK 20260905000000_add_claims.sql (61.62ms)11912026/09/29 08:18:14 OK 20260920000000_drop_claims.sql (50.29ms)11922026/09/29 08:18:14 OK 20260923120000_add_pushes.sql (29.01ms)11932026/09/29 08:18:14 goose: successfully migrated database to version: 2026092312000011942026/09/29 08:18:14 OK 1_commit_pending_closure.sql (1.21ms)11952026/09/29 08:18:14 OK 2_object_stats_trigger.sql (261.67µs)11962026/09/29 08:18:14 OK 3_commit_push.sql (228.46µs)11972026/09/29 08:18:14 goose: up to current file version: 311982026-09-29 08:18:14.402 UTC [10538] ERROR: relation "goose_db_version" does not exist at character 3611992026-09-29 08:18:14.402 UTC [10538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12002026-09-29 08:18:14.402 UTC [10537] ERROR: relation "goose_db_version" does not exist at character 3612012026-09-29 08:18:14.402 UTC [10537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12022026/09/29 08:18:14 INFO Received cleanup request method=DELETE path=/api/pending_closures12032026/09/29 08:18:14 INFO Aborted multipart uploads count=012042026/09/29 08:18:14 INFO Received uploads request method=POST path=/api/pending_closures12052026/09/29 08:18:14 OK 20241026095416_initial_model.sql (161.31ms)12062026/09/29 08:18:14 INFO Received cleanup request method=DELETE path=/api/pending_closures12072026/09/29 08:18:14 OK 20241026095416_initial_model.sql (32.27ms)12082026/09/29 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (8.33ms)12092026/09/29 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (9.37ms)12102026/09/29 08:18:14 INFO Aborted multipart uploads count=112112026/09/29 08:18:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12122026-09-29 08:18:14.509 UTC [10524] ERROR: Closure does not exist: id=112132026-09-29 08:18:14.509 UTC [10524] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12142026-09-29 08:18:14.509 UTC [10524] STATEMENT: -- name: CommitPendingClosure :exec1215 SELECT commit_pending_closure($1::bigint)1216 1217--- PASS: TestService_cleanupPendingClosuresHandler (2.22s)1218=== CONT TestService_healthCheckHandler12192026/09/29 08:18:14 OK 20251218171726_add_pins.sql (26.76ms)12202026/09/29 08:18:14 OK 20251218171726_add_pins.sql (27.41ms)12212026/09/29 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (19.88ms)12222026/09/29 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (35ms)12232026/09/29 08:18:14 OK 20260905000000_add_claims.sql (31.35ms)12242026/09/29 08:18:14 OK 20241026095416_initial_model.sql (121.54ms)12252026/09/29 08:18:14 OK 20260905000000_add_claims.sql (18.79ms)12262026/09/29 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (6.29ms)12272026/09/29 08:18:14 OK 20260920000000_drop_claims.sql (8.68ms)12282026/09/29 08:18:14 OK 20260920000000_drop_claims.sql (11.48ms)12292026/09/29 08:18:14 OK 20260923120000_add_pushes.sql (10.48ms)12302026/09/29 08:18:14 goose: successfully migrated database to version: 2026092312000012312026/09/29 08:18:14 OK 1_commit_pending_closure.sql (1.68ms)12322026/09/29 08:18:14 OK 2_object_stats_trigger.sql (388.42µs)12332026/09/29 08:18:14 OK 3_commit_push.sql (230.25µs)12342026/09/29 08:18:14 goose: up to current file version: 312352026/09/29 08:18:14 OK 20260923120000_add_pushes.sql (13.92ms)12362026/09/29 08:18:14 goose: successfully migrated database to version: 2026092312000012372026/09/29 08:18:14 OK 20251218171726_add_pins.sql (19.62ms)12382026/09/29 08:18:14 OK 1_commit_pending_closure.sql (859.17µs)12392026/09/29 08:18:14 OK 2_object_stats_trigger.sql (213.67µs)12402026/09/29 08:18:14 OK 3_commit_push.sql (165.25µs)12412026/09/29 08:18:14 goose: up to current file version: 312422026/09/29 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (18.42ms)12432026/09/29 08:18:14 INFO Aborted multipart uploads count=012442026/09/29 08:18:14 WARN Force mode enabled - objects will be deleted immediately without grace period12452026/09/29 08:18:14 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=012462026/09/29 08:18:14 INFO Vacuumed table table=pending_closures12472026/09/29 08:18:14 INFO Vacuumed table table=pending_objects12482026/09/29 08:18:14 INFO Vacuumed table table=multipart_uploads12492026/09/29 08:18:14 INFO Vacuumed table table=closures12502026/09/29 08:18:14 INFO Vacuumed table table=objects1251--- PASS: TestGCMetrics (2.04s)1252=== CONT TestGracefulShutdownDrainsInflight12532026/09/29 08:18:14 INFO Starting HTTP server address=127.0.0.1:5666012542026/09/29 08:18:14 INFO Shutdown signal received, draining in-flight requests timeout=10s12552026/09/29 08:18:14 OK 20260905000000_add_claims.sql (34.73ms)12562026/09/29 08:18:14 OK 20260920000000_drop_claims.sql (28.82ms)12572026/09/29 08:18:14 OK 20260923120000_add_pushes.sql (15.1ms)12582026/09/29 08:18:14 goose: successfully migrated database to version: 2026092312000012592026/09/29 08:18:14 OK 1_commit_pending_closure.sql (13.64ms)1260--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1261=== CONT TestGCTaskStore_Fail1262--- PASS: TestGCTaskStore_Fail (0.00s)1263=== CONT TestGCTaskStore_PhaseUpdates1264--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1265=== CONT TestGCTaskStore_CompletedAllowsNewTask1266--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1267=== CONT TestGCTaskStore_GetReturnsLatest1268--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1269=== CONT TestGCTaskStore_GetEmpty1270--- PASS: TestGCTaskStore_GetEmpty (0.00s)1271=== CONT TestGCTaskStore_ConflictDifferentParams1272--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1273=== CONT TestGCTaskStore_DeduplicateSameParams1274--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1275=== CONT TestGCTaskStore_StartNew1276--- PASS: TestGCTaskStore_StartNew (0.00s)1277=== CONT TestSkippedUploadsHandler12782026/09/29 08:18:14 OK 2_object_stats_trigger.sql (1.78ms)12792026/09/29 08:18:14 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001280--- PASS: TestSkippedUploadsHandler (0.00s)1281=== CONT TestPush_RejectsBadRequests12822026/09/29 08:18:14 OK 3_commit_push.sql (510.83µs)12832026/09/29 08:18:14 goose: up to current file version: 312842026-09-29 08:18:14.784 UTC [10548] ERROR: relation "goose_db_version" does not exist at character 3612852026-09-29 08:18:14.784 UTC [10548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12862026/09/29 08:18:14 INFO Received uploads request method=POST path=/api/pending_closures12872026/09/29 08:18:14 OK 20241026095416_initial_model.sql (74ms)12882026/09/29 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (11.88ms)12892026-09-29 08:18:14.932 UTC [10550] ERROR: relation "goose_db_version" does not exist at character 3612902026-09-29 08:18:14.932 UTC [10550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12912026/09/29 08:18:14 OK 20251218171726_add_pins.sql (19.57ms)12922026/09/29 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (24.91ms)12932026/09/29 08:18:15 OK 20260905000000_add_claims.sql (55.87ms)12942026/09/29 08:18:15 OK 20260920000000_drop_claims.sql (41.03ms)12952026/09/29 08:18:15 OK 20241026095416_initial_model.sql (111.5ms)12962026/09/29 08:18:15 OK 20260923120000_add_pushes.sql (15.94ms)12972026/09/29 08:18:15 goose: successfully migrated database to version: 2026092312000012982026/09/29 08:18:15 OK 1_commit_pending_closure.sql (1.89ms)12992026/09/29 08:18:15 OK 2_object_stats_trigger.sql (387.21µs)13002026/09/29 08:18:15 OK 3_commit_push.sql (202µs)13012026/09/29 08:18:15 goose: up to current file version: 313022026/09/29 08:18:15 OK 20251210153512_drop_unused_gin_index.sql (17.53ms)13032026/09/29 08:18:15 OK 20251218171726_add_pins.sql (24.19ms)13042026/09/29 08:18:15 OK 20260628120000_add_object_size_and_stats.sql (24.53ms)13052026/09/29 08:18:15 OK 20260905000000_add_claims.sql (40.19ms)13062026/09/29 08:18:15 OK 20260920000000_drop_claims.sql (43.92ms)13072026/09/29 08:18:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1308--- PASS: TestObjectStatsTrigger (2.39s)1309=== CONT TestPush_SignsNarinfosOfItsPendingObjects13102026/09/29 08:18:15 OK 20260923120000_add_pushes.sql (31.72ms)13112026/09/29 08:18:15 goose: successfully migrated database to version: 2026092312000013122026/09/29 08:18:15 OK 1_commit_pending_closure.sql (2.19ms)13132026/09/29 08:18:15 OK 2_object_stats_trigger.sql (1.38ms)13142026/09/29 08:18:15 OK 3_commit_push.sql (539.04µs)13152026/09/29 08:18:15 goose: up to current file version: 313162026/09/29 08:18:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13172026/09/29 08:18:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1318--- PASS: TestService_NativeMTLS (2.08s)1319=== CONT TestClientIntegration13202026-09-29 08:18:15.621 UTC [10576] ERROR: relation "goose_db_version" does not exist at character 3613212026-09-29 08:18:15.621 UTC [10576] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13222026/09/29 08:18:15 OK 20241026095416_initial_model.sql (95.56ms)13232026/09/29 08:18:15 OK 20251210153512_drop_unused_gin_index.sql (51.39ms)13242026/09/29 08:18:15 INFO Received uploads request method=POST path=/api/pending_closures13252026/09/29 08:18:15 OK 20251218171726_add_pins.sql (64.22ms)13262026/09/29 08:18:15 OK 20260628120000_add_object_size_and_stats.sql (32.9ms)13272026-09-29 08:18:15.950 UTC [10593] ERROR: relation "goose_db_version" does not exist at character 3613282026-09-29 08:18:15.950 UTC [10593] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13292026/09/29 08:18:15 OK 20260905000000_add_claims.sql (21.45ms)13302026/09/29 08:18:16 OK 20260920000000_drop_claims.sql (37.79ms)13312026/09/29 08:18:16 OK 20260923120000_add_pushes.sql (16ms)13322026/09/29 08:18:16 goose: successfully migrated database to version: 2026092312000013332026/09/29 08:18:16 OK 1_commit_pending_closure.sql (6.9ms)13342026/09/29 08:18:16 OK 2_object_stats_trigger.sql (8.28ms)13352026/09/29 08:18:16 OK 3_commit_push.sql (8.43ms)13362026/09/29 08:18:16 goose: up to current file version: 313372026/09/29 08:18:16 OK 20241026095416_initial_model.sql (56.93ms)13382026/09/29 08:18:16 INFO Received cleanup request method=DELETE path=/api/pending_closures13392026/09/29 08:18:16 INFO Aborted multipart uploads count=113402026/09/29 08:18:16 OK 20251210153512_drop_unused_gin_index.sql (24.33ms)13412026/09/29 08:18:16 OK 20251218171726_add_pins.sql (19.14ms)1342--- PASS: TestMultipartCleanup (3.00s)1343=== CONT TestGCBugBareHashReferences13442026/09/29 08:18:16 OK 20260628120000_add_object_size_and_stats.sql (28.64ms)13452026/09/29 08:18:16 OK 20260905000000_add_claims.sql (30.95ms)13462026/09/29 08:18:16 OK 20260920000000_drop_claims.sql (18.71ms)13472026-09-29 08:18:16.192 UTC [10613] ERROR: relation "goose_db_version" does not exist at character 3613482026-09-29 08:18:16.192 UTC [10613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13492026/09/29 08:18:16 OK 20260923120000_add_pushes.sql (21.77ms)13502026/09/29 08:18:16 goose: successfully migrated database to version: 2026092312000013512026/09/29 08:18:16 OK 1_commit_pending_closure.sql (7.11ms)13522026/09/29 08:18:16 OK 2_object_stats_trigger.sql (1.67ms)13532026/09/29 08:18:16 OK 3_commit_push.sql (1.29ms)13542026/09/29 08:18:16 goose: up to current file version: 31355--- PASS: TestMetricsInventory (2.88s)1356=== CONT TestLeadEndsOnShutdown13572026/09/29 08:18:16 OK 20241026095416_initial_model.sql (134.2ms)13582026/09/29 08:18:16 OK 20251210153512_drop_unused_gin_index.sql (11.87ms)13592026/09/29 08:18:16 OK 20251218171726_add_pins.sql (29.22ms)13602026/09/29 08:18:16 OK 20260628120000_add_object_size_and_stats.sql (39.59ms)13612026/09/29 08:18:16 OK 20260905000000_add_claims.sql (57.03ms)13622026-09-29 08:18:16.532 UTC [10627] ERROR: relation "goose_db_version" does not exist at character 3613632026-09-29 08:18:16.532 UTC [10627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13642026/09/29 08:18:16 OK 20260920000000_drop_claims.sql (24.15ms)13652026/09/29 08:18:16 OK 20260923120000_add_pushes.sql (16.96ms)13662026/09/29 08:18:16 goose: successfully migrated database to version: 2026092312000013672026/09/29 08:18:16 OK 1_commit_pending_closure.sql (1.07ms)13682026/09/29 08:18:16 OK 2_object_stats_trigger.sql (261.54µs)13692026/09/29 08:18:16 OK 3_commit_push.sql (202.46µs)13702026/09/29 08:18:16 goose: up to current file version: 31371=== NAME TestNARDeduplicationMetadataUploadBug1372 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-9673-972427610/TestNARDeduplicationMetadataUploadBug1997637363/001/store/897bn4ixh3sx2zdyi64qxcmwkphh3ra6-file1.txt13732026/09/29 08:18:16 OK 20241026095416_initial_model.sql (117.35ms)13742026/09/29 08:18:16 OK 20251210153512_drop_unused_gin_index.sql (16.69ms)13752026/09/29 08:18:16 OK 20251218171726_add_pins.sql (17.83ms)13762026/09/29 08:18:16 OK 20260628120000_add_object_size_and_stats.sql (25.46ms)13772026/09/29 08:18:16 WARN readiness check failed error="closed pool"1378--- PASS: TestService_readinessHandler (2.84s)1379=== CONT TestLeadElectsOneAndHandsOver13802026/09/29 08:18:16 OK 20260905000000_add_claims.sql (30.81ms)13812026/09/29 08:18:16 INFO Received push request method=POST path=/api/pushes13822026/09/29 08:18:16 OK 20260920000000_drop_claims.sql (18.4ms)13832026/09/29 08:18:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13842026/09/29 08:18:16 INFO Uploading 897bn4ixh3sx2zdyi64qxcmwkphh3ra6-file1.txt (160B)13852026/09/29 08:18:16 OK 20260923120000_add_pushes.sql (7.77ms)13862026/09/29 08:18:16 goose: successfully migrated database to version: 2026092312000013872026/09/29 08:18:16 OK 1_commit_pending_closure.sql (1.55ms)13882026/09/29 08:18:16 OK 2_object_stats_trigger.sql (269.29µs)13892026/09/29 08:18:16 OK 3_commit_push.sql (226.08µs)13902026/09/29 08:18:16 goose: up to current file version: 313912026/09/29 08:18:16 WARN Failed to register uploaded object key=897bn4ixh3sx2zdyi64qxcmwkphh3ra6.ls error="server returned 404: 404 page not found\n"13922026/09/29 08:18:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13932026/09/29 08:18:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13942026/09/29 08:18:16 INFO Signed narinfos id=1 count=113952026/09/29 08:18:16 INFO Uploading 1 narinfos13962026/09/29 08:18:16 INFO Received complete push request method=POST path=/api/pushes/1/complete13972026/09/29 08:18:16 WARN Failed to register uploaded object key=897bn4ixh3sx2zdyi64qxcmwkphh3ra6.narinfo error="server returned 404: 404 page not found\n"13982026/09/29 08:18:16 INFO Upload complete. (122ms)1399=== NAME TestNARDeduplicationMetadataUploadBug1400 metadata_upload_test.go:54: Retrieved narinfo from S3:1401 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestNARDeduplicationMetadataUploadBug1997637363/001/store/897bn4ixh3sx2zdyi64qxcmwkphh3ra6-file1.txt1402 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1403 Compression: zstd1404 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1405 NarSize: 1601406 References: 1407 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1408 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1409 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1410 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1411 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-9673-972427610/TestNARDeduplicationMetadataUploadBug1997637363/001/store/9wkvi5g68xjldg1shwlisiij1hc8bvww-file2.txt1412--- PASS: TestService_healthCheckHandler (2.50s)1413=== CONT TestResolveDBConnectionString1414=== RUN TestResolveDBConnectionString/flag_wins1415=== PAUSE TestResolveDBConnectionString/flag_wins1416=== RUN TestResolveDBConnectionString/file_when_flag_empty1417=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1418=== RUN TestResolveDBConnectionString/missing_file_is_an_error1419=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1420=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1421=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1422=== RUN TestResolveDBConnectionString/nothing_configured1423=== PAUSE TestResolveDBConnectionString/nothing_configured1424=== CONT TestClientFallsBackToClosures14252026/09/29 08:18:17 INFO Received push request method=POST path=/api/pushes14262026/09/29 08:18:17 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14272026/09/29 08:18:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14282026/09/29 08:18:17 INFO Signed narinfos id=2 count=114292026/09/29 08:18:17 INFO Uploading 1 narinfos14302026/09/29 08:18:17 WARN Failed to register uploaded object key=9wkvi5g68xjldg1shwlisiij1hc8bvww.ls error="server returned 404: 404 page not found\n"14312026/09/29 08:18:17 INFO Received complete push request method=POST path=/api/pushes/2/complete14322026/09/29 08:18:17 WARN Failed to register uploaded object key=9wkvi5g68xjldg1shwlisiij1hc8bvww.narinfo error="server returned 404: 404 page not found\n"14332026/09/29 08:18:17 INFO Upload complete. (96ms)1434=== NAME TestNARDeduplicationMetadataUploadBug1435 metadata_upload_test.go:76: Retrieved narinfo from S3:1436 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestNARDeduplicationMetadataUploadBug1997637363/001/store/9wkvi5g68xjldg1shwlisiij1hc8bvww-file2.txt1437 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1438 Compression: zstd1439 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1440 NarSize: 1601441 References: 1442 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1443 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1444 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1445 {"version":1,"root":{"type":"regular","size":44}}1446--- PASS: TestNARDeduplicationMetadataUploadBug (3.40s)1447=== CONT TestClientPushesUseOnePush1448=== RUN TestPush_RejectsBadRequests/no_roots1449=== PAUSE TestPush_RejectsBadRequests/no_roots1450=== RUN TestPush_RejectsBadRequests/no_objects1451=== PAUSE TestPush_RejectsBadRequests/no_objects1452=== RUN TestPush_RejectsBadRequests/bad_root1453=== PAUSE TestPush_RejectsBadRequests/bad_root1454=== RUN TestPush_RejectsBadRequests/root_not_in_objects1455=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1456=== CONT TestPinProtectsFromGC14572026-09-29 08:18:17.355 UTC [10670] ERROR: relation "goose_db_version" does not exist at character 3614582026-09-29 08:18:17.355 UTC [10670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14592026/09/29 08:18:17 OK 20241026095416_initial_model.sql (168.61ms)14602026/09/29 08:18:17 OK 20251210153512_drop_unused_gin_index.sql (9.95ms)14612026/09/29 08:18:17 OK 20251218171726_add_pins.sql (33.84ms)14622026/09/29 08:18:17 OK 20260628120000_add_object_size_and_stats.sql (60.22ms)14632026/09/29 08:18:17 OK 20260905000000_add_claims.sql (52.61ms)1464=== NAME TestClientIntegration1465 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-9673-972427610/TestClientIntegration325630446/002/store/qywzniq16nsgqgw97j84cnjs7maknmi9-test-file.txt14662026/09/29 08:18:17 OK 20260920000000_drop_claims.sql (37.25ms)14672026/09/29 08:18:17 OK 20260923120000_add_pushes.sql (9.33ms)14682026/09/29 08:18:17 goose: successfully migrated database to version: 2026092312000014692026/09/29 08:18:17 OK 1_commit_pending_closure.sql (897.38µs)14702026/09/29 08:18:17 OK 2_object_stats_trigger.sql (232.38µs)14712026/09/29 08:18:17 OK 3_commit_push.sql (211.29µs)14722026/09/29 08:18:17 goose: up to current file version: 314732026/09/29 08:18:17 INFO Received push request method=POST path=/api/pushes14742026/09/29 08:18:17 INFO Received push request method=POST path=/api/pushes14752026-09-29 08:18:17.867 UTC [10676] ERROR: relation "goose_db_version" does not exist at character 3614762026-09-29 08:18:17.867 UTC [10676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14772026/09/29 08:18:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14782026/09/29 08:18:17 INFO Signed narinfos id=1 count=11479--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.63s)1480=== CONT TestClientSharedPathCommittedMidPush14812026/09/29 08:18:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14822026/09/29 08:18:17 INFO Uploading qywzniq16nsgqgw97j84cnjs7maknmi9-test-file.txt (152B)14832026/09/29 08:18:17 WARN Failed to register uploaded object key=qywzniq16nsgqgw97j84cnjs7maknmi9.ls error="server returned 404: 404 page not found\n"14842026/09/29 08:18:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14852026/09/29 08:18:17 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14862026/09/29 08:18:17 INFO Signed narinfos id=1 count=114872026/09/29 08:18:17 INFO Uploading 1 narinfos14882026/09/29 08:18:17 INFO Received complete push request method=POST path=/api/pushes/1/complete14892026/09/29 08:18:17 WARN Failed to register uploaded object key=qywzniq16nsgqgw97j84cnjs7maknmi9.narinfo error="server returned 404: 404 page not found\n"14902026/09/29 08:18:17 INFO Upload complete. (174ms)14912026/09/29 08:18:18 INFO All 1 paths already cached1492=== NAME TestClientIntegration1493 client_integration_test.go:312: Retrieved narinfo from S3:1494 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientIntegration325630446/002/store/qywzniq16nsgqgw97j84cnjs7maknmi9-test-file.txt1495 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1496 Compression: zstd1497 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11498 NarSize: 1521499 References: 1500 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11501 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1502 client_integration_test.go:313: Decompressed .ls content (64 bytes):1503 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1504 client_integration_test.go:316: Testing garbage collection...15052026/09/29 08:18:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures15062026/09/29 08:18:18 INFO Garbage collection started15072026/09/29 08:18:18 INFO Aborted multipart uploads count=015082026/09/29 08:18:18 WARN Force mode enabled - objects will be deleted immediately without grace period15092026/09/29 08:18:18 OK 20241026095416_initial_model.sql (221ms)15102026/09/29 08:18:18 OK 20251210153512_drop_unused_gin_index.sql (14.09ms)15112026/09/29 08:18:18 OK 20251218171726_add_pins.sql (28.9ms)15122026/09/29 08:18:18 OK 20260628120000_add_object_size_and_stats.sql (27.29ms)15132026/09/29 08:18:18 OK 20260905000000_add_claims.sql (37.73ms)15142026/09/29 08:18:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=015152026/09/29 08:18:18 OK 20260920000000_drop_claims.sql (44.45ms)15162026/09/29 08:18:18 INFO Vacuumed table table=pending_closures15172026/09/29 08:18:18 OK 20260923120000_add_pushes.sql (21.75ms)15182026/09/29 08:18:18 goose: successfully migrated database to version: 2026092312000015192026/09/29 08:18:18 OK 1_commit_pending_closure.sql (1.17ms)15202026/09/29 08:18:18 OK 2_object_stats_trigger.sql (247.33µs)15212026/09/29 08:18:18 OK 3_commit_push.sql (196.08µs)15222026/09/29 08:18:18 goose: up to current file version: 315232026/09/29 08:18:18 INFO Vacuumed table table=pending_objects15242026/09/29 08:18:18 INFO Vacuumed table table=multipart_uploads15252026-09-29 08:18:18.379 UTC [10689] ERROR: relation "goose_db_version" does not exist at character 3615262026-09-29 08:18:18.379 UTC [10689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15272026/09/29 08:18:18 INFO Vacuumed table table=closures1528--- PASS: TestGCBugBareHashReferences (2.30s)1529=== CONT TestClientWithDependencies15302026/09/29 08:18:18 INFO Vacuumed table table=objects15312026/09/29 08:18:18 INFO lead: acquired remote=192.0.2.1:123415322026/09/29 08:18:18 INFO lead: released remote=192.0.2.1:12341533--- PASS: TestLeadEndsOnShutdown (2.36s)1534=== CONT TestClientMultipleUploads15352026/09/29 08:18:18 OK 20241026095416_initial_model.sql (219.7ms)15362026/09/29 08:18:18 OK 20251210153512_drop_unused_gin_index.sql (13.23ms)15372026/09/29 08:18:18 OK 20251218171726_add_pins.sql (18.21ms)15382026/09/29 08:18:18 OK 20260628120000_add_object_size_and_stats.sql (35.78ms)15392026/09/29 08:18:18 OK 20260905000000_add_claims.sql (50.08ms)15402026/09/29 08:18:18 OK 20260920000000_drop_claims.sql (20.57ms)15412026/09/29 08:18:18 OK 20260923120000_add_pushes.sql (22.54ms)15422026/09/29 08:18:18 goose: successfully migrated database to version: 2026092312000015432026/09/29 08:18:18 OK 1_commit_pending_closure.sql (1.99ms)15442026/09/29 08:18:18 OK 2_object_stats_trigger.sql (474.42µs)15452026/09/29 08:18:18 OK 3_commit_push.sql (435.08µs)15462026/09/29 08:18:18 goose: up to current file version: 315472026-09-29 08:18:18.992 UTC [10694] ERROR: relation "goose_db_version" does not exist at character 3615482026-09-29 08:18:18.992 UTC [10694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15492026/09/29 08:18:19 INFO lead: acquired remote=192.0.2.1:123415502026/09/29 08:18:19 OK 20241026095416_initial_model.sql (129.79ms)15512026-09-29 08:18:19.182 UTC [10696] ERROR: relation "goose_db_version" does not exist at character 3615522026-09-29 08:18:19.182 UTC [10696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15532026/09/29 08:18:19 OK 20251210153512_drop_unused_gin_index.sql (8.28ms)15542026-09-29 08:18:19.200 UTC [10697] ERROR: relation "goose_db_version" does not exist at character 3615552026-09-29 08:18:19.200 UTC [10697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15562026/09/29 08:18:19 OK 20251218171726_add_pins.sql (11.08ms)15572026/09/29 08:18:19 OK 20260628120000_add_object_size_and_stats.sql (18.74ms)15582026/09/29 08:18:19 OK 20260905000000_add_claims.sql (23.04ms)15592026/09/29 08:18:19 OK 20260920000000_drop_claims.sql (18.23ms)15602026/09/29 08:18:19 OK 20260923120000_add_pushes.sql (2.55ms)15612026/09/29 08:18:19 goose: successfully migrated database to version: 2026092312000015622026/09/29 08:18:19 OK 1_commit_pending_closure.sql (1.77ms)15632026/09/29 08:18:19 OK 2_object_stats_trigger.sql (832.75µs)15642026/09/29 08:18:19 OK 3_commit_push.sql (1.65ms)15652026/09/29 08:18:19 goose: up to current file version: 315662026/09/29 08:18:19 OK 20241026095416_initial_model.sql (60.02ms)15672026/09/29 08:18:19 OK 20251210153512_drop_unused_gin_index.sql (9.77ms)15682026/09/29 08:18:19 INFO lead: released remote=192.0.2.1:123415692026/09/29 08:18:19 OK 20251218171726_add_pins.sql (28.11ms)15702026/09/29 08:18:19 OK 20241026095416_initial_model.sql (94.55ms)15712026/09/29 08:18:19 OK 20260628120000_add_object_size_and_stats.sql (10.07ms)15722026/09/29 08:18:19 OK 20251210153512_drop_unused_gin_index.sql (7.84ms)15732026/09/29 08:18:19 INFO lead: acquired remote=192.0.2.1:123415742026/09/29 08:18:19 INFO lead: released remote=192.0.2.1:12341575--- PASS: TestLeadElectsOneAndHandsOver (2.57s)1576=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected15772026/09/29 08:18:19 OK 20251218171726_add_pins.sql (24.43ms)15782026/09/29 08:18:19 OK 20260905000000_add_claims.sql (32.33ms)15792026/09/29 08:18:19 OK 20260920000000_drop_claims.sql (24.69ms)15802026/09/29 08:18:19 OK 20260628120000_add_object_size_and_stats.sql (32.56ms)15812026-09-29 08:18:19.391 UTC [10703] ERROR: relation "goose_db_version" does not exist at character 3615822026-09-29 08:18:19.391 UTC [10703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15832026/09/29 08:18:19 OK 20260923120000_add_pushes.sql (13.38ms)15842026/09/29 08:18:19 goose: successfully migrated database to version: 2026092312000015852026/09/29 08:18:19 OK 1_commit_pending_closure.sql (4.66ms)15862026/09/29 08:18:19 OK 2_object_stats_trigger.sql (670.17µs)15872026/09/29 08:18:19 OK 3_commit_push.sql (434.13µs)15882026/09/29 08:18:19 goose: up to current file version: 315892026/09/29 08:18:19 OK 20260905000000_add_claims.sql (59.72ms)15902026/09/29 08:18:19 OK 20260920000000_drop_claims.sql (19.64ms)15912026/09/29 08:18:19 OK 20260923120000_add_pushes.sql (15.17ms)15922026/09/29 08:18:19 goose: successfully migrated database to version: 2026092312000015932026/09/29 08:18:19 OK 1_commit_pending_closure.sql (1.05ms)15942026/09/29 08:18:19 OK 2_object_stats_trigger.sql (246µs)15952026/09/29 08:18:19 OK 3_commit_push.sql (214.33µs)15962026/09/29 08:18:19 goose: up to current file version: 315972026/09/29 08:18:19 OK 20241026095416_initial_model.sql (123.17ms)15982026/09/29 08:18:19 OK 20251210153512_drop_unused_gin_index.sql (5.9ms)1599=== NAME TestOrphanedObjectsGCStressTest1600 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16012026/09/29 08:18:19 OK 20251218171726_add_pins.sql (35.38ms)16022026/09/29 08:18:19 WARN Rate limiter enabled after throttle name=s3-test rate=516032026/09/29 08:18:19 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1604=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1605 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101606 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001607--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.14s)1608=== CONT TestService_ReadScope_PublicByDefault16092026/09/29 08:18:19 OK 20260628120000_add_object_size_and_stats.sql (45.79ms)1610=== NAME TestOrphanedObjectsGCStressTest1611 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16122026/09/29 08:18:19 OK 20260905000000_add_claims.sql (58.16ms)16132026/09/29 08:18:19 OK 20260920000000_drop_claims.sql (17.22ms)16142026/09/29 08:18:19 OK 20260923120000_add_pushes.sql (6.21ms)16152026/09/29 08:18:19 goose: successfully migrated database to version: 2026092312000016162026/09/29 08:18:19 OK 1_commit_pending_closure.sql (790.08µs)16172026/09/29 08:18:19 OK 2_object_stats_trigger.sql (211.58µs)16182026/09/29 08:18:19 OK 3_commit_push.sql (178.08µs)16192026/09/29 08:18:19 goose: up to current file version: 316202026-09-29 08:18:19.911 UTC [10714] ERROR: relation "goose_db_version" does not exist at character 3616212026-09-29 08:18:19.911 UTC [10714] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026/09/29 08:18:19 INFO Received uploads request method=POST path=/api/pending_closures16232026/09/29 08:18:20 INFO Received uploads request method=POST path=/api/pending_closures16242026/09/29 08:18:20 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16252026/09/29 08:18:20 INFO Uploading wbxzzcd7nz5932hgjkbr4w43w3q7qchh-b (248B)16262026/09/29 08:18:20 INFO Uploading p75bwqlwkmqndscm1qjqnh6jlv0460y6-shared-dep (136B)16272026/09/29 08:18:20 WARN Failed to register uploaded object key=wbxzzcd7nz5932hgjkbr4w43w3q7qchh.ls error="server returned 404: 404 page not found\n"16282026/09/29 08:18:20 WARN Failed to register uploaded object key=p75bwqlwkmqndscm1qjqnh6jlv0460y6.ls error="server returned 404: 404 page not found\n"16292026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/16kjaiincjcricms6rkqhxksnsg9s6qa6y78mldsps8c378jwvny.nar.zst error="server returned 404: 404 page not found\n"16302026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16312026/09/29 08:18:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01632=== NAME TestClientIntegration1633 client_integration_test.go:323: Objects in database after GC:16342026/09/29 08:18:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16352026/09/29 08:18:20 WARN Failed to register uploaded object key=ikr3xp757rqv9rl91ddfnviwk6lx7s1r.ls error="server returned 404: 404 page not found\n"16362026/09/29 08:18:20 INFO Signed narinfos id=1 count=21637 client_integration_test.go:323: Successfully deleted all objects with GC --force16382026/09/29 08:18:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16392026/09/29 08:18:20 INFO Signed narinfos id=2 count=216402026/09/29 08:18:20 INFO Uploading 4 narinfos16412026/09/29 08:18:20 WARN Failed to register uploaded object key=ikr3xp757rqv9rl91ddfnviwk6lx7s1r.narinfo error="server returned 404: 404 page not found\n"16422026/09/29 08:18:20 WARN Failed to register uploaded object key=wbxzzcd7nz5932hgjkbr4w43w3q7qchh.narinfo error="server returned 404: 404 page not found\n"16432026/09/29 08:18:20 OK 20241026095416_initial_model.sql (112.09ms)16442026/09/29 08:18:20 WARN Failed to register uploaded object key=p75bwqlwkmqndscm1qjqnh6jlv0460y6.narinfo error="server returned 404: 404 page not found\n"16452026/09/29 08:18:20 OK 20251210153512_drop_unused_gin_index.sql (10.54ms)1646--- PASS: TestClientIntegration (4.61s)1647=== CONT TestClientErrorHandling1648=== RUN TestClientErrorHandling/InvalidStorePath1649=== PAUSE TestClientErrorHandling/InvalidStorePath1650=== RUN TestClientErrorHandling/InvalidAuthToken1651=== PAUSE TestClientErrorHandling/InvalidAuthToken1652=== RUN TestClientErrorHandling/ServerNotAvailable1653=== PAUSE TestClientErrorHandling/ServerNotAvailable1654=== CONT TestClientCADerivations16552026/09/29 08:18:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16562026/09/29 08:18:20 WARN Failed to register uploaded object key=p75bwqlwkmqndscm1qjqnh6jlv0460y6.narinfo error="server returned 404: 404 page not found\n"16572026-09-29 08:18:20.093 UTC [10726] ERROR: relation "goose_db_version" does not exist at character 3616582026-09-29 08:18:20.093 UTC [10726] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16592026/09/29 08:18:20 OK 20251218171726_add_pins.sql (26.65ms)16602026/09/29 08:18:20 INFO Completed upload id=116612026/09/29 08:18:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16622026/09/29 08:18:20 INFO Completed upload id=216632026/09/29 08:18:20 INFO Upload complete. (163ms)1664=== NAME TestClientFallsBackToClosures1665 client_pushes_test.go:112: Retrieved narinfo from S3:1666 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientFallsBackToClosures172240644/001/store/p75bwqlwkmqndscm1qjqnh6jlv0460y6-shared-dep1667 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1668 Compression: zstd1669 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821670 NarSize: 1361671 References: 1672 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1673 client_pushes_test.go:112: Retrieved narinfo from S3:1674 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientFallsBackToClosures172240644/001/store/ikr3xp757rqv9rl91ddfnviwk6lx7s1r-a1675 URL: nar/16kjaiincjcricms6rkqhxksnsg9s6qa6y78mldsps8c378jwvny.nar.zst1676 Compression: zstd1677 NarHash: sha256:16kjaiincjcricms6rkqhxksnsg9s6qa6y78mldsps8c378jwvny1678 NarSize: 2481679 References: /nix/var/nix/builds/nix-9673-972427610/TestClientFallsBackToClosures172240644/001/store/p75bwqlwkmqndscm1qjqnh6jlv0460y6-shared-dep1680 CA: text:sha256:05xf8jy62rb5yrk55pv1a45x05j6cdwijr9ffwh4am31k2n8bnay1681 client_pushes_test.go:112: Retrieved narinfo from S3:1682 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientFallsBackToClosures172240644/001/store/wbxzzcd7nz5932hgjkbr4w43w3q7qchh-b1683 URL: nar/16kjaiincjcricms6rkqhxksnsg9s6qa6y78mldsps8c378jwvny.nar.zst1684 Compression: zstd1685 NarHash: sha256:16kjaiincjcricms6rkqhxksnsg9s6qa6y78mldsps8c378jwvny1686 NarSize: 2481687 References: /nix/var/nix/builds/nix-9673-972427610/TestClientFallsBackToClosures172240644/001/store/p75bwqlwkmqndscm1qjqnh6jlv0460y6-shared-dep1688 CA: text:sha256:05xf8jy62rb5yrk55pv1a45x05j6cdwijr9ffwh4am31k2n8bnay16892026/09/29 08:18:20 OK 20260628120000_add_object_size_and_stats.sql (18.05ms)1690--- PASS: TestClientFallsBackToClosures (3.11s)1691=== CONT TestCacheStatsHandler16922026/09/29 08:18:20 INFO Received push request method=POST path=/api/pushes16932026/09/29 08:18:20 OK 20260905000000_add_claims.sql (58.31ms)16942026/09/29 08:18:20 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16952026/09/29 08:18:20 INFO Uploading ppibvwbp76a8mr113l3fcr8lrdyk7lxq-a (248B)16962026/09/29 08:18:20 INFO Uploading zc3l79vipqh1n8czv3wf7qy7138qd51b-shared-dep (136B)16972026/09/29 08:18:20 OK 20260920000000_drop_claims.sql (12.46ms)16982026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16992026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/0yfvnhpwssd050sa0aw2mf6176lpic5151n8xmxf08hl5y0s241i.nar.zst error="server returned 404: 404 page not found\n"17002026/09/29 08:18:20 WARN Failed to register uploaded object key=101z1667lx5fiyszvilvdi36klm827b7.ls error="server returned 404: 404 page not found\n"17012026/09/29 08:18:20 WARN Failed to register uploaded object key=ppibvwbp76a8mr113l3fcr8lrdyk7lxq.ls error="server returned 404: 404 page not found\n"17022026/09/29 08:18:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17032026/09/29 08:18:20 WARN Failed to register uploaded object key=zc3l79vipqh1n8czv3wf7qy7138qd51b.ls error="server returned 404: 404 page not found\n"17042026/09/29 08:18:20 INFO Signed narinfos id=1 count=317052026/09/29 08:18:20 INFO Uploading 3 narinfos17062026/09/29 08:18:20 OK 20260923120000_add_pushes.sql (7.23ms)17072026/09/29 08:18:20 goose: successfully migrated database to version: 2026092312000017082026/09/29 08:18:20 OK 1_commit_pending_closure.sql (1.37ms)17092026/09/29 08:18:20 OK 2_object_stats_trigger.sql (251.38µs)17102026/09/29 08:18:20 OK 3_commit_push.sql (203.38µs)17112026/09/29 08:18:20 goose: up to current file version: 317122026/09/29 08:18:20 INFO Received complete push request method=POST path=/api/pushes/1/complete17132026/09/29 08:18:20 WARN Failed to register uploaded object key=101z1667lx5fiyszvilvdi36klm827b7.narinfo error="server returned 404: 404 page not found\n"17142026/09/29 08:18:20 WARN Failed to register uploaded object key=ppibvwbp76a8mr113l3fcr8lrdyk7lxq.narinfo error="server returned 404: 404 page not found\n"17152026/09/29 08:18:20 WARN Failed to register uploaded object key=zc3l79vipqh1n8czv3wf7qy7138qd51b.narinfo error="server returned 404: 404 page not found\n"1716=== NAME TestPinProtectsFromGC1717 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-9673-972427610/TestPinProtectsFromGC103155202/001/store/i3bxlkpm9hlizwzmqw6j16rfvailw8xr-pinned-file.txt1718 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-9673-972427610/TestPinProtectsFromGC103155202/001/store/dnqf22xhfhwasvmxdsiqz7qm4ah3b1qq-unpinned-file.txt17192026/09/29 08:18:20 INFO Upload complete. (144ms)1720=== NAME TestClientPushesUseOnePush1721 client_pushes_test.go:97: Retrieved narinfo from S3:1722 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientPushesUseOnePush3321793398/001/store/zc3l79vipqh1n8czv3wf7qy7138qd51b-shared-dep1723 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1724 Compression: zstd1725 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821726 NarSize: 1361727 References: 1728 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1729 client_pushes_test.go:97: Retrieved narinfo from S3:1730 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientPushesUseOnePush3321793398/001/store/ppibvwbp76a8mr113l3fcr8lrdyk7lxq-a1731 URL: nar/0yfvnhpwssd050sa0aw2mf6176lpic5151n8xmxf08hl5y0s241i.nar.zst1732 Compression: zstd1733 NarHash: sha256:0yfvnhpwssd050sa0aw2mf6176lpic5151n8xmxf08hl5y0s241i1734 NarSize: 2481735 References: /nix/var/nix/builds/nix-9673-972427610/TestClientPushesUseOnePush3321793398/001/store/zc3l79vipqh1n8czv3wf7qy7138qd51b-shared-dep1736 CA: text:sha256:1vj195a0vbaiwjsifk3apq19wsp6kfwpqzh1kpr94fkswmkl19041737 client_pushes_test.go:97: Retrieved narinfo from S3:1738 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientPushesUseOnePush3321793398/001/store/101z1667lx5fiyszvilvdi36klm827b7-b1739 URL: nar/0yfvnhpwssd050sa0aw2mf6176lpic5151n8xmxf08hl5y0s241i.nar.zst1740 Compression: zstd1741 NarHash: sha256:0yfvnhpwssd050sa0aw2mf6176lpic5151n8xmxf08hl5y0s241i1742 NarSize: 2481743 References: /nix/var/nix/builds/nix-9673-972427610/TestClientPushesUseOnePush3321793398/001/store/zc3l79vipqh1n8czv3wf7qy7138qd51b-shared-dep1744 CA: text:sha256:1vj195a0vbaiwjsifk3apq19wsp6kfwpqzh1kpr94fkswmkl190417452026/09/29 08:18:20 OK 20241026095416_initial_model.sql (122.04ms)17462026/09/29 08:18:20 OK 20251210153512_drop_unused_gin_index.sql (6.01ms)1747--- PASS: TestClientPushesUseOnePush (3.07s)1748=== CONT TestCacheConfigHandler1749=== RUN TestCacheConfigHandler/full_config,_no_issuer1750=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1751=== RUN TestCacheConfigHandler/no_cache_url_configured1752=== PAUSE TestCacheConfigHandler/no_cache_url_configured1753=== RUN TestCacheConfigHandler/no_signing_keys1754=== PAUSE TestCacheConfigHandler/no_signing_keys1755=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1756=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1757=== CONT TestService_ReadAuthMiddleware17582026/09/29 08:18:20 OK 20251218171726_add_pins.sql (32.35ms)17592026/09/29 08:18:20 INFO Received push request method=POST path=/api/pushes17602026/09/29 08:18:20 OK 20260628120000_add_object_size_and_stats.sql (23.38ms)17612026/09/29 08:18:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17622026/09/29 08:18:20 INFO Uploading i3bxlkpm9hlizwzmqw6j16rfvailw8xr-pinned-file.txt (128B)17632026/09/29 08:18:20 WARN Failed to register uploaded object key=i3bxlkpm9hlizwzmqw6j16rfvailw8xr.ls error="server returned 404: 404 page not found\n"17642026/09/29 08:18:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17652026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17662026/09/29 08:18:20 INFO Signed narinfos id=1 count=117672026/09/29 08:18:20 INFO Uploading 1 narinfos17682026/09/29 08:18:20 OK 20260905000000_add_claims.sql (41.34ms)17692026/09/29 08:18:20 INFO Received complete push request method=POST path=/api/pushes/1/complete17702026/09/29 08:18:20 WARN Failed to register uploaded object key=i3bxlkpm9hlizwzmqw6j16rfvailw8xr.narinfo error="server returned 404: 404 page not found\n"17712026/09/29 08:18:20 INFO Upload complete. (117ms)17722026/09/29 08:18:20 OK 20260920000000_drop_claims.sql (32.62ms)17732026/09/29 08:18:20 OK 20260923120000_add_pushes.sql (16.53ms)17742026/09/29 08:18:20 goose: successfully migrated database to version: 2026092312000017752026/09/29 08:18:20 OK 1_commit_pending_closure.sql (1.26ms)17762026/09/29 08:18:20 OK 2_object_stats_trigger.sql (263µs)17772026/09/29 08:18:20 OK 3_commit_push.sql (212.67µs)17782026/09/29 08:18:20 goose: up to current file version: 317792026/09/29 08:18:20 INFO Received push request method=POST path=/api/pushes17802026/09/29 08:18:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17812026/09/29 08:18:20 INFO Uploading dnqf22xhfhwasvmxdsiqz7qm4ah3b1qq-unpinned-file.txt (128B)17822026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17832026/09/29 08:18:20 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17842026/09/29 08:18:20 WARN Failed to register uploaded object key=dnqf22xhfhwasvmxdsiqz7qm4ah3b1qq.ls error="server returned 404: 404 page not found\n"17852026/09/29 08:18:20 INFO Signed narinfos id=2 count=117862026/09/29 08:18:20 INFO Uploading 1 narinfos17872026/09/29 08:18:20 INFO Received complete push request method=POST path=/api/pushes/2/complete17882026/09/29 08:18:20 WARN Failed to register uploaded object key=dnqf22xhfhwasvmxdsiqz7qm4ah3b1qq.narinfo error="server returned 404: 404 page not found\n"17892026/09/29 08:18:20 INFO Upload complete. (93ms)17902026/09/29 08:18:20 INFO Received create pin request method=POST path=/api/pins/myapp17912026/09/29 08:18:20 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-9673-972427610/TestPinProtectsFromGC103155202/001/store/i3bxlkpm9hlizwzmqw6j16rfvailw8xr-pinned-file.txt narinfo_key=i3bxlkpm9hlizwzmqw6j16rfvailw8xr.narinfo17922026/09/29 08:18:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures17932026/09/29 08:18:20 INFO Garbage collection started17942026/09/29 08:18:20 INFO Aborted multipart uploads count=017952026/09/29 08:18:20 WARN Force mode enabled - objects will be deleted immediately without grace period17962026/09/29 08:18:20 INFO Received push request method=POST path=/api/pushes17972026-09-29 08:18:20.632 UTC [10762] ERROR: relation "goose_db_version" does not exist at character 3617982026-09-29 08:18:20.632 UTC [10762] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17992026/09/29 08:18:20 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18002026/09/29 08:18:20 INFO Uploading 4jf95ghqqd30zs3sja52w2v9ndkw77jy-shared-dep (136B)18012026/09/29 08:18:20 INFO Uploading kj7gm9prkh0sfv59mlls04xqg08x0nmv-top (256B)18022026/09/29 08:18:20 WARN Failed to register uploaded object key=4jf95ghqqd30zs3sja52w2v9ndkw77jy.ls error="server returned 404: 404 page not found\n"18032026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18042026/09/29 08:18:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18052026/09/29 08:18:20 WARN Failed to register uploaded object key=nar/1lfxdwcxz9ypk813bjhj8mf6p4cs9359w8mkarjr85gpans9qnqb.nar.zst error="server returned 404: 404 page not found\n"18062026/09/29 08:18:20 WARN Failed to register uploaded object key=kj7gm9prkh0sfv59mlls04xqg08x0nmv.ls error="server returned 404: 404 page not found\n"18072026/09/29 08:18:20 INFO Signed narinfos id=1 count=218082026/09/29 08:18:20 INFO Uploading 2 narinfos18092026/09/29 08:18:20 WARN Failed to register uploaded object key=kj7gm9prkh0sfv59mlls04xqg08x0nmv.narinfo error="server returned 404: 404 page not found\n"18102026/09/29 08:18:20 INFO Received complete push request method=POST path=/api/pushes/1/complete18112026/09/29 08:18:20 WARN Failed to register uploaded object key=4jf95ghqqd30zs3sja52w2v9ndkw77jy.narinfo error="server returned 404: 404 page not found\n"18122026/09/29 08:18:20 INFO Upload complete. (138ms)1813=== NAME TestClientSharedPathCommittedMidPush1814 client_integration_test.go:680: Retrieved narinfo from S3:1815 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientSharedPathCommittedMidPush657369592/001/store/4jf95ghqqd30zs3sja52w2v9ndkw77jy-shared-dep1816 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1817 Compression: zstd1818 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821819 NarSize: 1361820 References: 1821 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1822 client_integration_test.go:680: Retrieved narinfo from S3:1823 StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientSharedPathCommittedMidPush657369592/001/store/kj7gm9prkh0sfv59mlls04xqg08x0nmv-top1824 URL: nar/1lfxdwcxz9ypk813bjhj8mf6p4cs9359w8mkarjr85gpans9qnqb.nar.zst1825 Compression: zstd1826 NarHash: sha256:1lfxdwcxz9ypk813bjhj8mf6p4cs9359w8mkarjr85gpans9qnqb1827 NarSize: 2561828 References: /nix/var/nix/builds/nix-9673-972427610/TestClientSharedPathCommittedMidPush657369592/001/store/4jf95ghqqd30zs3sja52w2v9ndkw77jy-shared-dep1829 CA: text:sha256:029fawg2gl7mx171qg5qikk2n0ix4ffjpknrx9yrf8n02qqgnw7q1830--- PASS: TestClientSharedPathCommittedMidPush (2.87s)1831=== CONT TestService_RequireScope_OIDC18322026/09/29 08:18:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56741/oidc18332026-09-29 08:18:20.796 UTC [10772] ERROR: relation "goose_db_version" does not exist at character 3618342026-09-29 08:18:20.796 UTC [10772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18352026/09/29 08:18:20 OK 20241026095416_initial_model.sql (118.14ms)18362026/09/29 08:18:20 OK 20251210153512_drop_unused_gin_index.sql (8.16ms)18372026/09/29 08:18:20 OK 20251218171726_add_pins.sql (12.88ms)18382026/09/29 08:18:20 OK 20260628120000_add_object_size_and_stats.sql (21.09ms)18392026/09/29 08:18:20 OK 20260905000000_add_claims.sql (29ms)1840=== NAME TestClientMultipleUploads1841 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-9673-972427610/TestClientMultipleUploads2112491794/001/store/5yslbk0bl079gd2hmfqyhbl9g1rw61l4-test-file-0.txt18422026/09/29 08:18:20 OK 20260920000000_drop_claims.sql (12.8ms)18432026/09/29 08:18:20 OK 20260923120000_add_pushes.sql (3.52ms)18442026/09/29 08:18:20 goose: successfully migrated database to version: 2026092312000018452026/09/29 08:18:20 OK 1_commit_pending_closure.sql (1.12ms)18462026/09/29 08:18:20 OK 2_object_stats_trigger.sql (359.42µs)18472026/09/29 08:18:20 OK 3_commit_push.sql (214µs)18482026/09/29 08:18:20 goose: up to current file version: 318492026/09/29 08:18:20 OK 20241026095416_initial_model.sql (90.8ms)18502026/09/29 08:18:20 OK 20251210153512_drop_unused_gin_index.sql (7.09ms)18512026/09/29 08:18:20 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3003 objects-failed-to-delete=018522026/09/29 08:18:20 OK 20251218171726_add_pins.sql (19.68ms)1853=== NAME TestClientWithDependencies1854 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-9673-972427610/TestClientWithDependencies3441898668/001/store/q80wjqx9g6sv24v1gkispii9pfq4kbz9-test-script1855=== NAME TestClientMultipleUploads1856 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-9673-972427610/TestClientMultipleUploads2112491794/001/store/p4smgywsz9c6sv9f3vjhyswcqlbajj6i-test-file-1.txt18572026/09/29 08:18:20 INFO Vacuumed table table=pending_closures18582026/09/29 08:18:20 OK 20260628120000_add_object_size_and_stats.sql (34.07ms)18592026/09/29 08:18:20 INFO Vacuumed table table=pending_objects18602026/09/29 08:18:20 INFO Vacuumed table table=multipart_uploads1861=== NAME TestClientWithDependencies1862 client_integration_test.go:615: Found 1 dependencies (including self)18632026/09/29 08:18:21 INFO Vacuumed table table=closures18642026/09/29 08:18:21 INFO Vacuumed table table=objects1865=== NAME TestClientMultipleUploads1866 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-9673-972427610/TestClientMultipleUploads2112491794/001/store/m15k054vswjb7n1nqdmfrvfh3zl3hgky-test-file-2.txt18672026/09/29 08:18:21 OK 20260905000000_add_claims.sql (51.84ms)18682026/09/29 08:18:21 OK 20260920000000_drop_claims.sql (27.57ms)18692026/09/29 08:18:21 INFO Received push request method=POST path=/api/pushes18702026/09/29 08:18:21 OK 20260923120000_add_pushes.sql (20.56ms)18712026/09/29 08:18:21 goose: successfully migrated database to version: 2026092312000018722026/09/29 08:18:21 OK 1_commit_pending_closure.sql (1.27ms)18732026/09/29 08:18:21 OK 2_object_stats_trigger.sql (343.5µs)18742026/09/29 08:18:21 OK 3_commit_push.sql (200.58µs)18752026/09/29 08:18:21 goose: up to current file version: 318762026/09/29 08:18:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18772026/09/29 08:18:21 INFO Uploading q80wjqx9g6sv24v1gkispii9pfq4kbz9-test-script (136B)18782026/09/29 08:18:21 WARN Failed to register uploaded object key=q80wjqx9g6sv24v1gkispii9pfq4kbz9.ls error="server returned 404: 404 page not found\n"18792026/09/29 08:18:21 INFO Received push request method=POST path=/api/pushes18802026/09/29 08:18:21 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18812026/09/29 08:18:21 INFO Received push request method=POST path=/api/pushes18822026/09/29 08:18:21 WARN Failed to register uploaded object key=log/8bmd58xsgaabaz02kh709jr8bmf4gpig-test-script.drv error="server returned 404: 404 page not found\n"18832026/09/29 08:18:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18842026/09/29 08:18:21 INFO Signed narinfos id=1 count=118852026/09/29 08:18:21 INFO Uploading 1 narinfos18862026/09/29 08:18:21 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18872026/09/29 08:18:21 INFO Uploading p4smgywsz9c6sv9f3vjhyswcqlbajj6i-test-file-1.txt (160B)18882026/09/29 08:18:21 INFO Uploading 5yslbk0bl079gd2hmfqyhbl9g1rw61l4-test-file-0.txt (160B)18892026/09/29 08:18:21 INFO Uploading m15k054vswjb7n1nqdmfrvfh3zl3hgky-test-file-2.txt (160B)18902026/09/29 08:18:21 INFO Received complete push request method=POST path=/api/pushes/1/complete18912026/09/29 08:18:21 WARN Failed to register uploaded object key=q80wjqx9g6sv24v1gkispii9pfq4kbz9.narinfo error="server returned 404: 404 page not found\n"18922026/09/29 08:18:21 WARN Failed to register uploaded object key=m15k054vswjb7n1nqdmfrvfh3zl3hgky.ls error="server returned 404: 404 page not found\n"18932026/09/29 08:18:21 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18942026/09/29 08:18:21 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18952026/09/29 08:18:21 INFO Received complete push request method=POST path=/api/pushes/1/complete18962026/09/29 08:18:21 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18972026/09/29 08:18:21 WARN Failed to register uploaded object key=5yslbk0bl079gd2hmfqyhbl9g1rw61l4.ls error="server returned 404: 404 page not found\n"18982026/09/29 08:18:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18992026/09/29 08:18:21 WARN Failed to register uploaded object key=p4smgywsz9c6sv9f3vjhyswcqlbajj6i.ls error="server returned 404: 404 page not found\n"19002026/09/29 08:18:21 INFO Upload complete. (183ms)19012026/09/29 08:18:21 INFO Signed narinfos id=1 count=319022026/09/29 08:18:21 INFO Uploading 3 narinfos1903=== NAME TestClientWithDependencies1904 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-9673-972427610/TestClientWithDependencies3441898668/001/store) requires matching store prefix19052026/09/29 08:18:21 INFO Received push request method=POST path=/api/pushes19062026/09/29 08:18:21 INFO Received complete push request method=POST path=/api/pushes/1/complete19072026/09/29 08:18:21 WARN Failed to register uploaded object key=p4smgywsz9c6sv9f3vjhyswcqlbajj6i.narinfo error="server returned 404: 404 page not found\n"19082026/09/29 08:18:21 WARN Failed to register uploaded object key=5yslbk0bl079gd2hmfqyhbl9g1rw61l4.narinfo error="server returned 404: 404 page not found\n"19092026/09/29 08:18:21 WARN Failed to register uploaded object key=m15k054vswjb7n1nqdmfrvfh3zl3hgky.narinfo error="server returned 404: 404 page not found\n"19102026/09/29 08:18:21 INFO Upload complete. (182ms)1911=== NAME TestClientMultipleUploads1912 client_integration_test.go:369: Uploaded 3 paths in 215.288666ms19132026/09/29 08:18:21 INFO Received complete push request method=POST path=/api/pushes/2/complete19142026-09-29 08:18:21.275 UTC [10762] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo19152026-09-29 08:18:21.275 UTC [10762] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE19162026-09-29 08:18:21.275 UTC [10762] STATEMENT: -- name: CommitPush :exec1917 SELECT commit_push($1::bigint)1918 1919--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (1.92s)1920=== CONT TestService_AuthMiddleware_OIDC1921--- PASS: TestClientWithDependencies (2.89s)1922=== CONT TestPush_CompleteCommitsEveryRoot19232026/09/29 08:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56761/oidc1924--- PASS: TestClientMultipleUploads (2.69s)1925=== CONT TestReadProxyDisabled1926--- PASS: TestService_ReadScope_PublicByDefault (1.74s)1927=== CONT TestReadProxyRangeRequest19282026-09-29 08:18:21.452 UTC [10800] ERROR: relation "goose_db_version" does not exist at character 3619292026-09-29 08:18:21.452 UTC [10800] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19302026-09-29 08:18:21.455 UTC [10801] ERROR: relation "goose_db_version" does not exist at character 3619312026-09-29 08:18:21.455 UTC [10801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19322026-09-29 08:18:21.457 UTC [10802] ERROR: relation "goose_db_version" does not exist at character 3619332026-09-29 08:18:21.457 UTC [10802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19342026/09/29 08:18:21 OK 20241026095416_initial_model.sql (10.15ms)19352026/09/29 08:18:21 OK 20251210153512_drop_unused_gin_index.sql (457µs)19362026/09/29 08:18:21 OK 20251218171726_add_pins.sql (10.88ms)19372026/09/29 08:18:21 OK 20241026095416_initial_model.sql (34.22ms)19382026/09/29 08:18:21 OK 20260628120000_add_object_size_and_stats.sql (23.39ms)19392026/09/29 08:18:21 OK 20251210153512_drop_unused_gin_index.sql (12.11ms)19402026/09/29 08:18:21 OK 20241026095416_initial_model.sql (46.63ms)19412026/09/29 08:18:21 OK 20251210153512_drop_unused_gin_index.sql (706.96µs)19422026/09/29 08:18:21 OK 20260905000000_add_claims.sql (8.61ms)19432026/09/29 08:18:21 OK 20251218171726_add_pins.sql (1.29ms)19442026/09/29 08:18:21 OK 20260920000000_drop_claims.sql (1.36ms)19452026/09/29 08:18:21 OK 20251218171726_add_pins.sql (3.87ms)19462026/09/29 08:18:21 OK 20260923120000_add_pushes.sql (905.63µs)19472026/09/29 08:18:21 goose: successfully migrated database to version: 2026092312000019482026/09/29 08:18:21 OK 1_commit_pending_closure.sql (928.5µs)19492026/09/29 08:18:21 OK 2_object_stats_trigger.sql (226.96µs)19502026/09/29 08:18:21 OK 3_commit_push.sql (206.08µs)19512026/09/29 08:18:21 goose: up to current file version: 319522026/09/29 08:18:21 OK 20260628120000_add_object_size_and_stats.sql (38.85ms)19532026/09/29 08:18:21 OK 20260628120000_add_object_size_and_stats.sql (46.06ms)19542026/09/29 08:18:21 OK 20260905000000_add_claims.sql (25.95ms)19552026/09/29 08:18:21 OK 20260905000000_add_claims.sql (31.4ms)19562026/09/29 08:18:21 OK 20260920000000_drop_claims.sql (20.74ms)19572026/09/29 08:18:21 OK 20260920000000_drop_claims.sql (21.04ms)19582026/09/29 08:18:21 OK 20260923120000_add_pushes.sql (10.92ms)19592026/09/29 08:18:21 goose: successfully migrated database to version: 2026092312000019602026/09/29 08:18:21 OK 20260923120000_add_pushes.sql (11.26ms)19612026/09/29 08:18:21 goose: successfully migrated database to version: 2026092312000019622026/09/29 08:18:21 OK 1_commit_pending_closure.sql (1.36ms)19632026/09/29 08:18:21 OK 1_commit_pending_closure.sql (1.4ms)19642026/09/29 08:18:21 OK 2_object_stats_trigger.sql (244.17µs)19652026/09/29 08:18:21 OK 2_object_stats_trigger.sql (269µs)19662026/09/29 08:18:21 OK 3_commit_push.sql (188.92µs)19672026/09/29 08:18:21 goose: up to current file version: 319682026/09/29 08:18:21 OK 3_commit_push.sql (189.46µs)19692026/09/29 08:18:21 goose: up to current file version: 31970=== NAME TestOrphanedObjectsGCStressTest1971 orphaned_objects_gc_test.go:509: Stress test completed successfully:1972 orphaned_objects_gc_test.go:510: - Active objects preserved: 201973 orphaned_objects_gc_test.go:511: - Objects deleted: 2101974 orphaned_objects_gc_test.go:512: - Total GC'd: 2101975--- PASS: TestOrphanedObjectsGCStressTest (9.51s)1976=== CONT TestReadRedirectKeepsNarinfoProxied1977--- PASS: TestService_ReadAuthMiddleware (1.68s)1978=== CONT TestReadRedirectNar19792026-09-29 08:18:22.059 UTC [10812] ERROR: relation "goose_db_version" does not exist at character 3619802026-09-29 08:18:22.059 UTC [10812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1981=== NAME TestClientCADerivations1982 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-9673-972427610/TestClientCADerivations1035285811/001/store/d8rx8xbywf07r34dfqxk9zqkgg4vqddw-ca-test1983 client_ca_test.go:139: Found 1 dependencies (including self)1984--- PASS: TestCacheStatsHandler (2.07s)1985=== CONT TestCompletedNarNotReofferedAcrossClosures19862026/09/29 08:18:22 OK 20241026095416_initial_model.sql (82.16ms)19872026/09/29 08:18:22 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)19882026/09/29 08:18:22 OK 20251218171726_add_pins.sql (1.71ms)19892026-09-29 08:18:22.214 UTC [10820] ERROR: relation "goose_db_version" does not exist at character 3619902026-09-29 08:18:22.214 UTC [10820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19912026-09-29 08:18:22.215 UTC [10821] ERROR: relation "goose_db_version" does not exist at character 3619922026-09-29 08:18:22.215 UTC [10821] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19932026-09-29 08:18:22.230 UTC [10825] ERROR: relation "goose_db_version" does not exist at character 3619942026-09-29 08:18:22.230 UTC [10825] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19952026/09/29 08:18:22 OK 20260628120000_add_object_size_and_stats.sql (29.1ms)19962026/09/29 08:18:22 OK 20260905000000_add_claims.sql (2.92ms)19972026/09/29 08:18:22 OK 20260920000000_drop_claims.sql (1.35ms)19982026/09/29 08:18:22 OK 20260923120000_add_pushes.sql (8.19ms)19992026/09/29 08:18:22 goose: successfully migrated database to version: 2026092312000020002026/09/29 08:18:22 OK 1_commit_pending_closure.sql (1.13ms)20012026/09/29 08:18:22 OK 2_object_stats_trigger.sql (228.38µs)20022026/09/29 08:18:22 OK 3_commit_push.sql (190.29µs)20032026/09/29 08:18:22 goose: up to current file version: 320042026/09/29 08:18:22 INFO Received push request method=POST path=/api/pushes20052026-09-29 08:18:22.291 UTC [10828] ERROR: relation "goose_db_version" does not exist at character 3620062026-09-29 08:18:22.291 UTC [10828] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20072026/09/29 08:18:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20082026/09/29 08:18:22 INFO Uploading d8rx8xbywf07r34dfqxk9zqkgg4vqddw-ca-test (144B)20092026/09/29 08:18:22 WARN Failed to register uploaded object key=d8rx8xbywf07r34dfqxk9zqkgg4vqddw.ls error="server returned 404: 404 page not found\n"20102026/09/29 08:18:22 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20112026/09/29 08:18:22 WARN Failed to register uploaded object key=log/w58bc37icpymcpy7zpzlan7x8zpcs9pp-ca-test.drv error="server returned 404: 404 page not found\n"20122026/09/29 08:18:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20132026/09/29 08:18:22 INFO Signed narinfos id=1 count=120142026/09/29 08:18:22 INFO Uploading 1 narinfos20152026/09/29 08:18:22 OK 20241026095416_initial_model.sql (76.33ms)20162026/09/29 08:18:22 INFO Received complete push request method=POST path=/api/pushes/1/complete20172026/09/29 08:18:22 OK 20251210153512_drop_unused_gin_index.sql (12.85ms)20182026/09/29 08:18:22 WARN Failed to register uploaded object key=d8rx8xbywf07r34dfqxk9zqkgg4vqddw.narinfo error="server returned 404: 404 page not found\n"20192026/09/29 08:18:22 OK 20241026095416_initial_model.sql (94.64ms)20202026/09/29 08:18:22 OK 20251210153512_drop_unused_gin_index.sql (7.1ms)20212026/09/29 08:18:22 INFO Upload complete. (172ms)2022=== NAME TestClientCADerivations2023 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-9673-972427610/TestClientCADerivations1035285811/001/store/d8rx8xbywf07r34dfqxk9zqkgg4vqddw-ca-test2024 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2025 Compression: zstd2026 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2027 NarSize: 1442028 References: 2029 Deriver: /nix/var/nix/builds/nix-9673-972427610/TestClientCADerivations1035285811/001/store/w58bc37icpymcpy7zpzlan7x8zpcs9pp-ca-test.drv2030 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2031 client_ca_test.go:185: Checking for realisation files in S3...2032 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2033 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20342026/09/29 08:18:22 OK 20251218171726_add_pins.sql (25.52ms)20352026/09/29 08:18:22 OK 20251218171726_add_pins.sql (20.13ms)20362026/09/29 08:18:22 OK 20260628120000_add_object_size_and_stats.sql (27.86ms)20372026/09/29 08:18:22 OK 20260628120000_add_object_size_and_stats.sql (33.95ms)20382026/09/29 08:18:22 OK 20241026095416_initial_model.sql (136.78ms)20392026/09/29 08:18:22 OK 20260905000000_add_claims.sql (22.07ms)20402026/09/29 08:18:22 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)2041 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket44?endpoint=http://localhost:56606®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-9673-972427610/TestClientCADerivations1035285811/001/store'2042 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120432026/09/29 08:18:22 OK 20260905000000_add_claims.sql (16.31ms)20442026/09/29 08:18:22 OK 20251218171726_add_pins.sql (7.43ms)20452026/09/29 08:18:22 OK 20260920000000_drop_claims.sql (8.06ms)20462026/09/29 08:18:22 OK 20241026095416_initial_model.sql (85.32ms)20472026/09/29 08:18:22 OK 20260923120000_add_pushes.sql (8.31ms)20482026/09/29 08:18:22 goose: successfully migrated database to version: 2026092312000020492026/09/29 08:18:22 OK 1_commit_pending_closure.sql (934.71µs)20502026/09/29 08:18:22 OK 2_object_stats_trigger.sql (268.63µs)20512026/09/29 08:18:22 OK 3_commit_push.sql (168.71µs)20522026/09/29 08:18:22 goose: up to current file version: 320532026/09/29 08:18:22 OK 20251210153512_drop_unused_gin_index.sql (6.18ms)20542026/09/29 08:18:22 OK 20260920000000_drop_claims.sql (15.45ms)20552026/09/29 08:18:22 OK 20260923120000_add_pushes.sql (5.02ms)20562026/09/29 08:18:22 goose: successfully migrated database to version: 2026092312000020572026/09/29 08:18:22 OK 1_commit_pending_closure.sql (843.21µs)20582026/09/29 08:18:22 OK 2_object_stats_trigger.sql (216.21µs)20592026/09/29 08:18:22 OK 3_commit_push.sql (173.54µs)20602026/09/29 08:18:22 goose: up to current file version: 320612026/09/29 08:18:22 OK 20260628120000_add_object_size_and_stats.sql (27.09ms)2062--- PASS: TestClientCADerivations (2.35s)2063=== CONT TestPresignedUploadRegisteredBeforeCommit20642026/09/29 08:18:22 OK 20251218171726_add_pins.sql (13.97ms)20652026/09/29 08:18:22 OK 20260628120000_add_object_size_and_stats.sql (20.08ms)20662026/09/29 08:18:22 OK 20260905000000_add_claims.sql (26ms)20672026/09/29 08:18:22 OK 20260920000000_drop_claims.sql (6.53ms)20682026/09/29 08:18:22 OK 20260905000000_add_claims.sql (13.34ms)2069=== RUN TestService_RequireScope_OIDC/builder_may_write2070=== PAUSE TestService_RequireScope_OIDC/builder_may_write2071=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2072=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2073=== RUN TestService_RequireScope_OIDC/ops_may_admin2074=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2075=== RUN TestService_RequireScope_OIDC/ops_may_not_write2076=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2077=== RUN TestService_RequireScope_OIDC/reader_may_not_write2078=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2079=== RUN TestService_RequireScope_OIDC/static_token_may_admin2080=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2081=== RUN TestService_RequireScope_OIDC/static_token_may_write2082=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2083=== RUN TestService_RequireScope_OIDC/reader_may_read2084=== PAUSE TestService_RequireScope_OIDC/reader_may_read2085=== RUN TestService_RequireScope_OIDC/writer_implies_read2086=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2087=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2088=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2089=== CONT TestCompleteMultipartUpload_ErrorButObjectExists20902026/09/29 08:18:22 OK 20260923120000_add_pushes.sql (6.1ms)20912026/09/29 08:18:22 goose: successfully migrated database to version: 2026092312000020922026/09/29 08:18:22 OK 1_commit_pending_closure.sql (1.43ms)20932026/09/29 08:18:22 OK 2_object_stats_trigger.sql (311.46µs)20942026/09/29 08:18:22 OK 3_commit_push.sql (214.83µs)20952026/09/29 08:18:22 goose: up to current file version: 320962026/09/29 08:18:22 OK 20260920000000_drop_claims.sql (28.37ms)20972026/09/29 08:18:22 OK 20260923120000_add_pushes.sql (11.44ms)20982026/09/29 08:18:22 goose: successfully migrated database to version: 2026092312000020992026/09/29 08:18:22 OK 1_commit_pending_closure.sql (1.03ms)21002026/09/29 08:18:22 OK 2_object_stats_trigger.sql (222.17µs)21012026/09/29 08:18:22 OK 3_commit_push.sql (204.25µs)21022026/09/29 08:18:22 goose: up to current file version: 321032026/09/29 08:18:22 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3003 objects_failed=02104=== NAME TestPinProtectsFromGC2105 client_integration_test.go:794: Pin successfully protected closure from garbage collection2106--- PASS: TestPinProtectsFromGC (5.34s)2107=== CONT TestReadProxyConditionalGet21082026-09-29 08:18:22.681 UTC [10842] ERROR: relation "goose_db_version" does not exist at character 3621092026-09-29 08:18:22.681 UTC [10842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2110--- PASS: TestReadProxyDisabled (1.36s)2111=== CONT TestReadProxyRootRedirectsToIndexHTML21122026/09/29 08:18:22 OK 20241026095416_initial_model.sql (49.63ms)21132026/09/29 08:18:22 OK 20251210153512_drop_unused_gin_index.sql (8.05ms)21142026/09/29 08:18:22 OK 20251218171726_add_pins.sql (21.7ms)21152026/09/29 08:18:22 OK 20260628120000_add_object_size_and_stats.sql (38.25ms)21162026/09/29 08:18:22 OK 20260905000000_add_claims.sql (26.03ms)21172026/09/29 08:18:22 OK 20260920000000_drop_claims.sql (18.77ms)21182026/09/29 08:18:22 OK 20260923120000_add_pushes.sql (7.01ms)21192026/09/29 08:18:22 goose: successfully migrated database to version: 2026092312000021202026-09-29 08:18:22.892 UTC [10845] ERROR: relation "goose_db_version" does not exist at character 3621212026-09-29 08:18:22.892 UTC [10845] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21222026/09/29 08:18:22 OK 1_commit_pending_closure.sql (1.34ms)21232026/09/29 08:18:22 OK 2_object_stats_trigger.sql (270.54µs)21242026/09/29 08:18:22 OK 3_commit_push.sql (207.96µs)21252026/09/29 08:18:22 goose: up to current file version: 32126=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2127=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2128=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2129=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2130=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2131=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2132=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2133=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2134=== CONT TestReadProxyHead21352026/09/29 08:18:23 OK 20241026095416_initial_model.sql (74.02ms)21362026/09/29 08:18:23 OK 20251210153512_drop_unused_gin_index.sql (6.29ms)21372026/09/29 08:18:23 OK 20251218171726_add_pins.sql (7.34ms)21382026/09/29 08:18:23 OK 20260628120000_add_object_size_and_stats.sql (15.91ms)21392026/09/29 08:18:23 OK 20260905000000_add_claims.sql (34.26ms)21402026/09/29 08:18:23 OK 20260920000000_drop_claims.sql (8.94ms)21412026/09/29 08:18:23 OK 20260923120000_add_pushes.sql (5.97ms)21422026/09/29 08:18:23 goose: successfully migrated database to version: 2026092312000021432026/09/29 08:18:23 OK 1_commit_pending_closure.sql (999.46µs)21442026/09/29 08:18:23 OK 2_object_stats_trigger.sql (226.25µs)21452026/09/29 08:18:23 OK 3_commit_push.sql (186.21µs)21462026/09/29 08:18:23 goose: up to current file version: 321472026/09/29 08:18:23 INFO Received push request method=POST path=/api/pushes21482026/09/29 08:18:23 INFO Received complete push request method=POST path=/api/pushes/1/complete2149--- PASS: TestPush_CompleteCommitsEveryRoot (1.92s)2150=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21512026-09-29 08:18:23.337 UTC [10851] ERROR: relation "goose_db_version" does not exist at character 3621522026-09-29 08:18:23.337 UTC [10851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2153--- PASS: TestReadProxyRangeRequest (1.95s)2154=== CONT TestService_AuthMiddleware_MTLSProxyHeader21552026-09-29 08:18:23.500 UTC [10855] ERROR: relation "goose_db_version" does not exist at character 3621562026-09-29 08:18:23.500 UTC [10855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21572026-09-29 08:18:23.500 UTC [10854] ERROR: relation "goose_db_version" does not exist at character 3621582026-09-29 08:18:23.500 UTC [10854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21592026/09/29 08:18:23 OK 20241026095416_initial_model.sql (105.69ms)21602026/09/29 08:18:23 OK 20251210153512_drop_unused_gin_index.sql (11.88ms)21612026/09/29 08:18:23 OK 20251218171726_add_pins.sql (20.89ms)21622026/09/29 08:18:23 OK 20260628120000_add_object_size_and_stats.sql (15.72ms)21632026/09/29 08:18:23 OK 20260905000000_add_claims.sql (33.69ms)21642026/09/29 08:18:23 OK 20260920000000_drop_claims.sql (14.5ms)2165--- PASS: TestReadRedirectKeepsNarinfoProxied (1.93s)2166=== CONT TestReadProxyInvalidPath21672026/09/29 08:18:23 OK 20241026095416_initial_model.sql (97.12ms)21682026/09/29 08:18:23 OK 20260923120000_add_pushes.sql (40.1ms)21692026/09/29 08:18:23 goose: successfully migrated database to version: 2026092312000021702026/09/29 08:18:23 OK 1_commit_pending_closure.sql (837.33µs)21712026/09/29 08:18:23 OK 2_object_stats_trigger.sql (255.29µs)21722026/09/29 08:18:23 OK 3_commit_push.sql (209.13µs)21732026/09/29 08:18:23 goose: up to current file version: 321742026/09/29 08:18:23 OK 20251210153512_drop_unused_gin_index.sql (14.97ms)21752026/09/29 08:18:23 OK 20251218171726_add_pins.sql (6.33ms)21762026/09/29 08:18:23 OK 20241026095416_initial_model.sql (118.52ms)21772026/09/29 08:18:23 OK 20251210153512_drop_unused_gin_index.sql (11.1ms)21782026/09/29 08:18:23 OK 20260628120000_add_object_size_and_stats.sql (45.82ms)21792026/09/29 08:18:23 OK 20251218171726_add_pins.sql (41.85ms)21802026/09/29 08:18:23 OK 20260905000000_add_claims.sql (31.59ms)21812026/09/29 08:18:23 OK 20260628120000_add_object_size_and_stats.sql (26.47ms)21822026/09/29 08:18:23 OK 20260920000000_drop_claims.sql (20.95ms)21832026-09-29 08:18:23.760 UTC [10858] ERROR: relation "goose_db_version" does not exist at character 3621842026-09-29 08:18:23.760 UTC [10858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21852026/09/29 08:18:23 OK 20260905000000_add_claims.sql (30.23ms)21862026/09/29 08:18:23 OK 20260923120000_add_pushes.sql (11.62ms)21872026/09/29 08:18:23 goose: successfully migrated database to version: 2026092312000021882026/09/29 08:18:23 OK 1_commit_pending_closure.sql (1.49ms)21892026/09/29 08:18:23 OK 2_object_stats_trigger.sql (282.83µs)21902026/09/29 08:18:23 OK 3_commit_push.sql (201.5µs)21912026/09/29 08:18:23 goose: up to current file version: 321922026/09/29 08:18:23 OK 20260920000000_drop_claims.sql (12.54ms)21932026/09/29 08:18:23 OK 20260923120000_add_pushes.sql (1.19ms)21942026/09/29 08:18:23 goose: successfully migrated database to version: 2026092312000021952026/09/29 08:18:23 OK 1_commit_pending_closure.sql (934.21µs)21962026/09/29 08:18:23 OK 2_object_stats_trigger.sql (252.04µs)21972026/09/29 08:18:23 OK 3_commit_push.sql (1.06ms)21982026/09/29 08:18:23 goose: up to current file version: 321992026/09/29 08:18:23 OK 20241026095416_initial_model.sql (64.58ms)22002026-09-29 08:18:23.859 UTC [10859] ERROR: relation "goose_db_version" does not exist at character 3622012026-09-29 08:18:23.859 UTC [10859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22022026/09/29 08:18:23 OK 20251210153512_drop_unused_gin_index.sql (6.2ms)2203--- PASS: TestReadRedirectNar (1.92s)2204=== CONT TestReadProxy40422052026/09/29 08:18:23 OK 20251218171726_add_pins.sql (38.89ms)22062026/09/29 08:18:23 OK 20260628120000_add_object_size_and_stats.sql (25.64ms)22072026/09/29 08:18:24 OK 20260905000000_add_claims.sql (72.1ms)22082026/09/29 08:18:24 OK 20260920000000_drop_claims.sql (21.04ms)22092026/09/29 08:18:24 OK 20260923120000_add_pushes.sql (21.31ms)22102026/09/29 08:18:24 goose: successfully migrated database to version: 2026092312000022112026/09/29 08:18:24 OK 1_commit_pending_closure.sql (1.27ms)22122026/09/29 08:18:24 OK 2_object_stats_trigger.sql (240.33µs)22132026/09/29 08:18:24 OK 3_commit_push.sql (194.04µs)22142026/09/29 08:18:24 goose: up to current file version: 322152026/09/29 08:18:24 OK 20241026095416_initial_model.sql (169.67ms)22162026/09/29 08:18:24 OK 20251210153512_drop_unused_gin_index.sql (9.09ms)22172026/09/29 08:18:24 OK 20251218171726_add_pins.sql (25.42ms)22182026/09/29 08:18:24 INFO Received uploads request method=POST path=/api/pending_closures22192026/09/29 08:18:24 OK 20260628120000_add_object_size_and_stats.sql (15.3ms)22202026-09-29 08:18:24.206 UTC [10862] ERROR: relation "goose_db_version" does not exist at character 3622212026-09-29 08:18:24.206 UTC [10862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22222026/09/29 08:18:24 OK 20260905000000_add_claims.sql (69.15ms)22232026/09/29 08:18:24 OK 20260920000000_drop_claims.sql (52.4ms)22242026/09/29 08:18:24 OK 20260923120000_add_pushes.sql (46.56ms)22252026/09/29 08:18:24 goose: successfully migrated database to version: 2026092312000022262026/09/29 08:18:24 OK 1_commit_pending_closure.sql (1.14ms)22272026/09/29 08:18:24 OK 2_object_stats_trigger.sql (247.63µs)22282026/09/29 08:18:24 OK 3_commit_push.sql (192.5µs)22292026/09/29 08:18:24 goose: up to current file version: 322302026/09/29 08:18:24 INFO Received uploads request method=POST path=/api/pending_closures22312026/09/29 08:18:24 OK 20241026095416_initial_model.sql (147.29ms)22322026/09/29 08:18:24 OK 20251210153512_drop_unused_gin_index.sql (29.38ms)22332026/09/29 08:18:24 OK 20251218171726_add_pins.sql (33.43ms)22342026/09/29 08:18:24 OK 20260628120000_add_object_size_and_stats.sql (56.26ms)22352026-09-29 08:18:24.654 UTC [10863] ERROR: relation "goose_db_version" does not exist at character 3622362026-09-29 08:18:24.654 UTC [10863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22372026/09/29 08:18:24 OK 20260905000000_add_claims.sql (93.58ms)22382026/09/29 08:18:24 OK 20260920000000_drop_claims.sql (59.41ms)22392026/09/29 08:18:24 OK 20260923120000_add_pushes.sql (19.97ms)22402026/09/29 08:18:24 goose: successfully migrated database to version: 2026092312000022412026/09/29 08:18:24 OK 1_commit_pending_closure.sql (1.07ms)22422026/09/29 08:18:24 OK 2_object_stats_trigger.sql (247.08µs)22432026/09/29 08:18:24 OK 3_commit_push.sql (207µs)22442026/09/29 08:18:24 goose: up to current file version: 322452026/09/29 08:18:24 INFO Received uploads request method=POST path=/api/pending_closures22462026/09/29 08:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22472026/09/29 08:18:24 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mzg0NjRiY2ItZmUwNy00N2Q4LThjMWEtZjIwNTg1MjkxOTIyLjI0ZmZjYWQ4LTY1MDgtNGVlZi1iMjVlLWFiNDEyMDQzZjY4YngxNzkwNjY5OTA0NTEwODM5MDAw22482026/09/29 08:18:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mzg0NjRiY2ItZmUwNy00N2Q4LThjMWEtZjIwNTg1MjkxOTIyLjI0ZmZjYWQ4LTY1MDgtNGVlZi1iMjVlLWFiNDEyMDQzZjY4YngxNzkwNjY5OTA0NTEwODM5MDAw parts=12249--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.36s)2250=== CONT TestIsValidCachePath/narinfo2251=== CONT TestIsValidCachePath/index.html2252=== CONT TestIsValidCachePath/short_hash2253=== CONT TestIsValidCachePath/wrong_extension2254=== CONT TestIsValidCachePath/leading_slash2255=== CONT TestIsValidCachePath/empty2256=== CONT TestIsValidCachePath/random_path2257=== CONT TestIsValidCachePath/invalid_char_u2258=== CONT TestIsValidCachePath/invalid_char_e2259=== CONT TestIsValidCachePath/traversal_in_middle2260=== CONT TestIsValidCachePath/traversal_parent2261=== CONT TestIsValidCachePath/nar_uncompressed2262=== CONT TestIsValidCachePath/nix-cache-info2263=== CONT TestIsValidCachePath/realisation2264=== CONT TestIsValidCachePath/log2265=== CONT TestIsValidCachePath/ls2266=== CONT TestIsValidCachePath/nar_xz2267=== CONT TestIsValidCachePath/nar_bz22268=== CONT TestIsValidCachePath/nar_zst2269=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2270--- PASS: TestIsValidCachePath (0.00s)2271 --- PASS: TestIsValidCachePath/narinfo (0.00s)2272 --- PASS: TestIsValidCachePath/index.html (0.00s)2273 --- PASS: TestIsValidCachePath/short_hash (0.00s)2274 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2275 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2276 --- PASS: TestIsValidCachePath/empty (0.00s)2277 --- PASS: TestIsValidCachePath/random_path (0.00s)2278 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2279 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2280 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2281 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2282 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2283 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2284 --- PASS: TestIsValidCachePath/realisation (0.00s)2285 --- PASS: TestIsValidCachePath/log (0.00s)2286 --- PASS: TestIsValidCachePath/ls (0.00s)2287 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2288 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2289 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2290 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2291=== CONT TestParseSingleRange/none2292=== CONT TestParseSingleRange/open-ended2293=== CONT TestParseSingleRange/start_far_past_EOF2294=== CONT TestParseSingleRange/start_past_EOF2295=== CONT TestParseSingleRange/single_byte2296=== CONT TestParseSingleRange/suffix_exceeds_size2297=== CONT TestParseSingleRange/suffix2298=== CONT TestParseSingleRange/end_clamped_to_size2299=== CONT TestParseSingleRange/malformed_both_empty2300=== CONT TestParseSingleRange/closed2301=== CONT TestParseSingleRange/malformed_end_before_start2302=== CONT TestParseSingleRange/multi-range_ignored2303=== CONT TestParseSingleRange/malformed_no_dash2304=== CONT TestParseSingleRange/unknown_unit2305--- PASS: TestParseSingleRange (0.00s)2306 --- PASS: TestParseSingleRange/none (0.00s)2307 --- PASS: TestParseSingleRange/open-ended (0.00s)2308 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2309 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2310 --- PASS: TestParseSingleRange/single_byte (0.00s)2311 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2312 --- PASS: TestParseSingleRange/suffix (0.00s)2313 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2314 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2315 --- PASS: TestParseSingleRange/closed (0.00s)2316 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2317 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2318 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2319 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2320=== CONT TestIsValidUploadKey/narinfo2321=== CONT TestIsValidUploadKey/realisation_plus_in_output2322=== CONT TestIsValidUploadKey/unknown_type2323=== CONT TestIsValidUploadKey/empty_key2324=== CONT TestIsValidUploadKey/absolute2325=== CONT TestIsValidUploadKey/traversal_nar2326=== CONT TestIsValidUploadKey/traversal2327=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2328=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2329=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2330=== CONT TestIsValidUploadKey/index.html2331=== CONT TestIsValidUploadKey/nix-cache-info2332=== CONT TestIsValidUploadKey/build_log_home-manager_file2333=== CONT TestIsValidUploadKey/realisation2334=== CONT TestIsValidUploadKey/build_log_equals2335=== CONT TestIsValidUploadKey/build_log_question_mark2336=== CONT TestIsValidUploadKey/build_log_plus_in_name2337=== CONT TestIsValidUploadKey/nar_plain2338=== CONT TestIsValidUploadKey/build_log2339=== CONT TestIsValidUploadKey/listing2340=== CONT TestIsValidUploadKey/nar_xz2341=== CONT TestIsValidUploadKey/nar_zst2342--- PASS: TestIsValidUploadKey (0.00s)2343 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2344 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2345 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2346 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2347 --- PASS: TestIsValidUploadKey/absolute (0.00s)2348 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2349 --- PASS: TestIsValidUploadKey/traversal (0.00s)2350 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2351 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2352 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2353 --- PASS: TestIsValidUploadKey/index.html (0.00s)2354 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2355 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2356 --- PASS: TestIsValidUploadKey/realisation (0.00s)2357 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2358 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2359 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2360 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2361 --- PASS: TestIsValidUploadKey/build_log (0.00s)2362 --- PASS: TestIsValidUploadKey/listing (0.00s)2363 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2364 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2365=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23662026/09/29 08:18:24 INFO Received uploads request method=POST path=/23672026/09/29 08:18:24 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst23682026/09/29 08:18:24 INFO Received uploads request method=POST path=/api/pending_closures2369--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.47s)2370=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23712026/09/29 08:18:24 INFO Received request for more parts method=POST path=/2372=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23732026/09/29 08:18:24 INFO Received complete multipart upload request method=POST path=/2374=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23752026/09/29 08:18:24 INFO Received uploads request method=POST path=/2376=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23772026/09/29 08:18:24 INFO Received complete multipart upload request method=POST path=/2378=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23792026/09/29 08:18:24 INFO Received request for more parts method=POST path=/2380=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23812026/09/29 08:18:24 INFO Received uploads request method=POST path=/2382--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2383 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2384 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2385 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2386 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2387=== CONT TestProxyWriteTimeout/narinfo2388=== CONT TestProxyWriteTimeout/10_GiB_nar2389=== CONT TestProxyWriteTimeout/unknown_size2390=== CONT TestProxyWriteTimeout/1_GiB_nar2391--- PASS: TestProxyWriteTimeout (0.00s)2392 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2393 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2394 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2395 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2396=== CONT TestServerTLSConfig/no_client_CA2397=== CONT TestServerTLSConfig/not_a_PEM_file2398=== CONT TestServerTLSConfig/missing_CA_file2399--- PASS: TestServerTLSConfig (0.00s)2400 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2401 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.04s)2402 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2403=== CONT TestResolveDBConnectionString/flag_wins2404=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2405=== CONT TestResolveDBConnectionString/nothing_configured2406=== CONT TestResolveDBConnectionString/missing_file_is_an_error2407=== CONT TestResolveDBConnectionString/file_when_flag_empty2408=== CONT TestPush_RejectsBadRequests/no_roots24092026/09/29 08:18:24 INFO Received push request method=POST path=/api/pushes2410=== CONT TestPush_RejectsBadRequests/bad_root24112026/09/29 08:18:24 INFO Received push request method=POST path=/api/pushes2412=== CONT TestPush_RejectsBadRequests/root_not_in_objects24132026/09/29 08:18:24 INFO Received push request method=POST path=/api/pushes2414=== CONT TestPush_RejectsBadRequests/no_objects24152026/09/29 08:18:24 INFO Received push request method=POST path=/api/pushes2416=== CONT TestClientErrorHandling/InvalidStorePath2417--- PASS: TestPush_RejectsBadRequests (2.55s)2418 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2419 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2420 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2421 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2422--- PASS: TestResolveDBConnectionString (0.03s)2423 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2424 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2425 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2426 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2427 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)24282026/09/29 08:18:25 OK 20241026095416_initial_model.sql (312.32ms)24292026/09/29 08:18:25 OK 20251210153512_drop_unused_gin_index.sql (7.05ms)24302026/09/29 08:18:25 OK 20251218171726_add_pins.sql (44.04ms)2431--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)2432 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2433 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2434 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2435=== CONT TestClientErrorHandling/ServerNotAvailable24362026/09/29 08:18:25 OK 20260628120000_add_object_size_and_stats.sql (51.9ms)24372026/09/29 08:18:25 OK 20260905000000_add_claims.sql (72.09ms)2438--- PASS: TestReadProxyConditionalGet (2.66s)2439=== CONT TestClientErrorHandling/InvalidAuthToken24402026/09/29 08:18:25 OK 20260920000000_drop_claims.sql (76.16ms)24412026/09/29 08:18:25 OK 20260923120000_add_pushes.sql (22.04ms)24422026/09/29 08:18:25 goose: successfully migrated database to version: 2026092312000024432026/09/29 08:18:25 OK 1_commit_pending_closure.sql (966.04µs)24442026/09/29 08:18:25 OK 2_object_stats_trigger.sql (220.96µs)24452026/09/29 08:18:25 OK 3_commit_push.sql (200.75µs)24462026/09/29 08:18:25 goose: up to current file version: 324472026-09-29 08:18:25.398 UTC [10871] ERROR: relation "goose_db_version" does not exist at character 3624482026-09-29 08:18:25.398 UTC [10871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24492026/09/29 08:18:25 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2450--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.91s)2451=== CONT TestCacheConfigHandler/full_config,_no_issuer2452=== CONT TestCacheConfigHandler/no_signing_keys2453=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator24542026/09/29 08:18:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.414237ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2455=== CONT TestCacheConfigHandler/no_cache_url_configured2456--- PASS: TestCacheConfigHandler (0.00s)2457 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2458 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2459 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2460 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2461=== CONT TestService_RequireScope_OIDC/builder_may_write2462=== CONT TestService_RequireScope_OIDC/static_token_may_admin2463=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2464=== CONT TestService_RequireScope_OIDC/writer_implies_read2465=== CONT TestService_RequireScope_OIDC/reader_may_read2466=== CONT TestService_RequireScope_OIDC/static_token_may_write2467=== CONT TestService_RequireScope_OIDC/ops_may_not_write2468=== CONT TestService_RequireScope_OIDC/reader_may_not_write2469=== CONT TestService_RequireScope_OIDC/ops_may_admin2470=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2471=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2472=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected24732026/09/29 08:18:25 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]2474=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2475=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected24762026/09/29 08:18:25 WARN Authentication failed token_preview=eyJhbGciOi...wMXJldhKyw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2477--- PASS: TestService_RequireScope_OIDC (1.73s)2478 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2479 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2480 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2481 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2482 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2483 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2484 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2485 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2486 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2487 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)24882026-09-29 08:18:25.621 UTC [10874] ERROR: relation "goose_db_version" does not exist at character 3624892026-09-29 08:18:25.621 UTC [10874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2490--- PASS: TestService_AuthMiddleware_OIDC (1.66s)2491 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2492 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2493 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2494 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)24952026/09/29 08:18:25 OK 20241026095416_initial_model.sql (184.38ms)24962026/09/29 08:18:25 OK 20251210153512_drop_unused_gin_index.sql (5.4ms)24972026/09/29 08:18:25 OK 20251218171726_add_pins.sql (37.31ms)24982026/09/29 08:18:25 OK 20260628120000_add_object_size_and_stats.sql (30.79ms)24992026/09/29 08:18:25 OK 20260905000000_add_claims.sql (53.74ms)25002026/09/29 08:18:25 OK 20260920000000_drop_claims.sql (11.5ms)25012026/09/29 08:18:25 OK 20241026095416_initial_model.sql (115.49ms)25022026/09/29 08:18:25 OK 20260923120000_add_pushes.sql (9.81ms)25032026/09/29 08:18:25 goose: successfully migrated database to version: 2026092312000025042026/09/29 08:18:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.424494ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25052026/09/29 08:18:25 OK 1_commit_pending_closure.sql (1.43ms)25062026/09/29 08:18:25 OK 2_object_stats_trigger.sql (1.4ms)25072026/09/29 08:18:25 OK 3_commit_push.sql (508.83µs)25082026/09/29 08:18:25 goose: up to current file version: 325092026/09/29 08:18:25 OK 20251210153512_drop_unused_gin_index.sql (13.34ms)25102026-09-29 08:18:25.814 UTC [10875] ERROR: relation "goose_db_version" does not exist at character 3625112026-09-29 08:18:25.814 UTC [10875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25122026/09/29 08:18:25 OK 20251218171726_add_pins.sql (30.45ms)25132026/09/29 08:18:25 OK 20260628120000_add_object_size_and_stats.sql (39.56ms)2514--- PASS: TestReadProxyHead (2.97s)25152026/09/29 08:18:25 OK 20260905000000_add_claims.sql (41.27ms)25162026/09/29 08:18:25 OK 20260920000000_drop_claims.sql (21.4ms)25172026/09/29 08:18:25 OK 20260923120000_add_pushes.sql (2.43ms)25182026/09/29 08:18:25 goose: successfully migrated database to version: 2026092312000025192026/09/29 08:18:25 OK 1_commit_pending_closure.sql (1.78ms)25202026/09/29 08:18:25 OK 2_object_stats_trigger.sql (747.42µs)25212026/09/29 08:18:25 OK 3_commit_push.sql (651.96µs)25222026/09/29 08:18:25 goose: up to current file version: 325232026/09/29 08:18:26 OK 20241026095416_initial_model.sql (143.65ms)25242026/09/29 08:18:26 OK 20251210153512_drop_unused_gin_index.sql (8.15ms)25252026/09/29 08:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25262026/09/29 08:18:26 OK 20251218171726_add_pins.sql (66.41ms)25272026/09/29 08:18:26 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Mzg0NjRiY2ItZmUwNy00N2Q4LThjMWEtZjIwNTg1MjkxOTIyLmY2ZmFhNGE3LTBkYjItNDg2OS04NDlmLWYwZGE3NDBhZDgxMHgxNzkwNjY5OTA0MTcwNDA0MDAw parts=1225282026/09/29 08:18:26 INFO Received uploads request method=POST path=/api/pending_closures2529--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.93s)25302026/09/29 08:18:26 OK 20260628120000_add_object_size_and_stats.sql (55.55ms)25312026/09/29 08:18:26 OK 20260905000000_add_claims.sql (37.65ms)25322026/09/29 08:18:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"25332026/09/29 08:18:26 WARN mTLS auth: bound subjects configured but subject DN unavailable25342026/09/29 08:18:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2535--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (3.00s)25362026/09/29 08:18:26 OK 20260920000000_drop_claims.sql (28.96ms)25372026/09/29 08:18:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.403859ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25382026/09/29 08:18:26 OK 20260923120000_add_pushes.sql (19.01ms)25392026/09/29 08:18:26 goose: successfully migrated database to version: 2026092312000025402026/09/29 08:18:26 OK 1_commit_pending_closure.sql (2.66ms)25412026/09/29 08:18:26 OK 2_object_stats_trigger.sql (378.25µs)25422026/09/29 08:18:26 OK 3_commit_push.sql (221.63µs)25432026/09/29 08:18:26 goose: up to current file version: 32544--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.13s)25452026-09-29 08:18:26.783 UTC [10879] ERROR: relation "goose_db_version" does not exist at character 3625462026-09-29 08:18:26.783 UTC [10879] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2547--- PASS: TestReadProxyInvalidPath (3.18s)25482026-09-29 08:18:26.840 UTC [10880] ERROR: relation "goose_db_version" does not exist at character 3625492026-09-29 08:18:26.840 UTC [10880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25502026/09/29 08:18:26 OK 20241026095416_initial_model.sql (88.73ms)25512026/09/29 08:18:26 OK 20251210153512_drop_unused_gin_index.sql (7.17ms)25522026/09/29 08:18:26 OK 20251218171726_add_pins.sql (15.87ms)25532026/09/29 08:18:26 OK 20241026095416_initial_model.sql (92.03ms)25542026/09/29 08:18:26 OK 20260628120000_add_object_size_and_stats.sql (14.27ms)25552026/09/29 08:18:26 OK 20251210153512_drop_unused_gin_index.sql (8.07ms)25562026/09/29 08:18:26 OK 20251218171726_add_pins.sql (14.65ms)25572026/09/29 08:18:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.685570309s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25582026/09/29 08:18:26 OK 20260905000000_add_claims.sql (32.71ms)25592026/09/29 08:18:27 OK 20260920000000_drop_claims.sql (13.56ms)25602026/09/29 08:18:27 OK 20260628120000_add_object_size_and_stats.sql (23.78ms)25612026/09/29 08:18:27 OK 20260923120000_add_pushes.sql (6.29ms)25622026/09/29 08:18:27 goose: successfully migrated database to version: 202609231200002563--- PASS: TestReadProxy404 (3.14s)25642026/09/29 08:18:27 OK 1_commit_pending_closure.sql (1.63ms)25652026/09/29 08:18:27 OK 2_object_stats_trigger.sql (546.71µs)25662026/09/29 08:18:27 OK 3_commit_push.sql (414.25µs)25672026/09/29 08:18:27 goose: up to current file version: 325682026/09/29 08:18:27 OK 20260905000000_add_claims.sql (42.5ms)25692026/09/29 08:18:27 OK 20260920000000_drop_claims.sql (22.2ms)25702026/09/29 08:18:27 OK 20260923120000_add_pushes.sql (17.84ms)25712026/09/29 08:18:27 goose: successfully migrated database to version: 2026092312000025722026/09/29 08:18:27 OK 1_commit_pending_closure.sql (1.24ms)25732026/09/29 08:18:27 OK 2_object_stats_trigger.sql (473.29µs)25742026/09/29 08:18:27 OK 3_commit_push.sql (400µs)25752026/09/29 08:18:27 goose: up to current file version: 325762026/09/29 08:18:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25772026/09/29 08:18:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25782026/09/29 08:18:28 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25792026/09/29 08:18:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.911477ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25802026/09/29 08:18:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.249936ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25812026/09/29 08:18:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.803525ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25822026/09/29 08:18:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.751725553s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25832026/09/29 08:18:32 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 127.0.0.1:19999: connect: connection refused"25842026/09/29 08:18:32 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25852026/09/29 08:18:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.22501ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25862026/09/29 08:18:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.611907ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25872026/09/29 08:18:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=871.140963ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25882026/09/29 08:18:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.445685562s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25892026/09/29 08:18:35 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25902026/09/29 08:18:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.87866ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25912026/09/29 08:18:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=386.219105ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25922026/09/29 08:18:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.804225ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25932026/09/29 08:18:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.577124556s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2594--- PASS: TestClientErrorHandling (0.00s)2595 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.25s)2596 --- PASS: TestClientErrorHandling/InvalidStorePath (2.53s)2597 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.15s)2598PASS2599{"timestamp":"2026-09-29T08:18:38.286498Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56652","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(8)"}26002026-09-29 08:18:38.396 UTC [9907] LOG: received smart shutdown request26012026-09-29 08:18:38.397 UTC [9907] LOG: background worker "logical replication launcher" (PID 9917) exited with exit code 126022026-09-29 08:18:38.430 UTC [9912] LOG: shutting down26032026-09-29 08:18:38.430 UTC [9912] LOG: checkpoint starting: shutdown immediate26042026-09-29 08:18:39.538 UTC [9912] LOG: checkpoint complete: wrote 12742 buffers (77.8%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.701 s, sync=0.370 s, total=1.109 s; sync files=21874, longest=0.001 s, average=0.001 s; distance=302637 kB, estimate=302637 kB; lsn=0/13F18740, redo lsn=0/13F1874026052026-09-29 08:18:39.543 UTC [9907] LOG: database system is shut down2606Running OIDC tests...2607=== RUN TestAudienceForIssuer2608=== PAUSE TestAudienceForIssuer2609=== RUN TestGlobMatch2610=== PAUSE TestGlobMatch2611=== RUN TestValidateToken_ValidToken2612=== PAUSE TestValidateToken_ValidToken2613=== RUN TestValidateToken_WrongAudience2614=== PAUSE TestValidateToken_WrongAudience2615=== RUN TestValidateToken_Expired2616=== PAUSE TestValidateToken_Expired2617=== RUN TestValidateToken_BoundClaimsMismatch2618=== PAUSE TestValidateToken_BoundClaimsMismatch2619=== RUN TestValidateToken_BoundSubjectMismatch2620=== PAUSE TestValidateToken_BoundSubjectMismatch2621=== RUN TestValidateToken_MultipleProviders2622=== PAUSE TestValidateToken_MultipleProviders2623=== RUN TestValidateToken_NoMatchingProvider2624=== PAUSE TestValidateToken_NoMatchingProvider2625=== RUN TestValidateToken_KubernetesServiceAccount2626=== PAUSE TestValidateToken_KubernetesServiceAccount2627=== RUN TestNewValidator_KubernetesRequiresCA2628=== PAUSE TestNewValidator_KubernetesRequiresCA2629=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2630=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2631=== RUN TestPins_ReservedForMatchingRule2632=== PAUSE TestPins_ReservedForMatchingRule2633=== RUN TestPins_TopLevelShorthand2634=== PAUSE TestPins_TopLevelShorthand2635=== RUN TestPins_ConfigValidation2636=== PAUSE TestPins_ConfigValidation2637=== RUN TestScopes_LegacyProviderDefaultsToWrite2638=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2639=== RUN TestScopes_Rules2640=== PAUSE TestScopes_Rules2641=== RUN TestScopes_ConfigValidation2642=== PAUSE TestScopes_ConfigValidation2643=== CONT TestAudienceForIssuer2644--- PASS: TestAudienceForIssuer (0.00s)2645=== CONT TestValidateToken_Expired2646=== CONT TestValidateToken_KubernetesServiceAccount2647=== CONT TestValidateToken_BoundClaimsMismatch2648=== CONT TestValidateToken_ValidToken2649=== CONT TestValidateToken_MultipleProviders2650=== CONT TestValidateToken_NoMatchingProvider2651=== CONT TestValidateToken_BoundSubjectMismatch2652=== CONT TestValidateToken_WrongAudience2653=== CONT TestPins_ConfigValidation2654=== CONT TestScopes_Rules2655--- PASS: TestPins_ConfigValidation (0.00s)2656=== CONT TestScopes_LegacyProviderDefaultsToWrite26572026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56872/oidc26582026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56874/oidc2659--- PASS: TestValidateToken_ValidToken (0.03s)2660=== CONT TestGlobMatch2661=== RUN TestGlobMatch/foo_foo2662=== PAUSE TestGlobMatch/foo_foo2663=== RUN TestGlobMatch/foo_bar2664=== PAUSE TestGlobMatch/foo_bar2665=== RUN TestGlobMatch/*_2666=== PAUSE TestGlobMatch/*_2667=== RUN TestGlobMatch/*_anything2668=== PAUSE TestGlobMatch/*_anything2669=== RUN TestGlobMatch/foo*_foo2670=== PAUSE TestGlobMatch/foo*_foo2671=== RUN TestGlobMatch/foo*_foobar2672=== PAUSE TestGlobMatch/foo*_foobar2673=== RUN TestGlobMatch/foo*_bar2674=== PAUSE TestGlobMatch/foo*_bar2675=== RUN TestGlobMatch/*bar_bar2676=== PAUSE TestGlobMatch/*bar_bar2677=== RUN TestGlobMatch/*bar_foobar2678=== PAUSE TestGlobMatch/*bar_foobar2679=== RUN TestGlobMatch/*bar_foo2680=== PAUSE TestGlobMatch/*bar_foo2681=== RUN TestGlobMatch/foo*bar_foobar2682=== PAUSE TestGlobMatch/foo*bar_foobar2683=== RUN TestGlobMatch/foo*bar_foo123bar2684=== PAUSE TestGlobMatch/foo*bar_foo123bar2685=== RUN TestGlobMatch/foo*bar_foobarbaz2686=== PAUSE TestGlobMatch/foo*bar_foobarbaz2687=== RUN TestGlobMatch/*/*_foo/bar2688=== PAUSE TestGlobMatch/*/*_foo/bar2689=== RUN TestGlobMatch/*/*_foo2690=== PAUSE TestGlobMatch/*/*_foo2691=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2692=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2693=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02694=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02695=== RUN TestGlobMatch/refs/*/main_refs/heads/main2696=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2697=== RUN TestGlobMatch/fo?_foo2698=== PAUSE TestGlobMatch/fo?_foo2699=== RUN TestGlobMatch/fo?_fo2700=== PAUSE TestGlobMatch/fo?_fo2701=== RUN TestGlobMatch/fo?_fooo2702=== PAUSE TestGlobMatch/fo?_fooo2703=== RUN TestGlobMatch/?oo_foo2704=== PAUSE TestGlobMatch/?oo_foo2705=== RUN TestGlobMatch/?oo_boo2706=== PAUSE TestGlobMatch/?oo_boo2707=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2708=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2709=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2710--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2711=== CONT TestPins_TopLevelShorthand2712=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2713=== CONT TestPins_ReservedForMatchingRule27142026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56876/oidc2715--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)2716=== CONT TestValidateToken_KubernetesIssuerFromOwnToken27172026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56878/oidc2718--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)2719=== CONT TestNewValidator_KubernetesRequiresCA27202026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56880/oidc27212026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56882/oidc2722--- PASS: TestPins_ReservedForMatchingRule (0.03s)2723=== CONT TestScopes_ConfigValidation2724--- PASS: TestScopes_ConfigValidation (0.00s)2725=== CONT TestGlobMatch/foo_foo2726=== CONT TestGlobMatch/*/*_foo/bar2727=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2728=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2729=== CONT TestGlobMatch/?oo_boo2730=== CONT TestGlobMatch/?oo_foo2731=== CONT TestGlobMatch/fo?_fooo2732=== CONT TestGlobMatch/fo?_fo2733=== CONT TestGlobMatch/fo?_foo2734=== CONT TestGlobMatch/refs/*/main_refs/heads/main2735=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02736=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2737=== CONT TestGlobMatch/*/*_foo2738=== CONT TestGlobMatch/*bar_bar2739=== CONT TestGlobMatch/foo*bar_foobarbaz2740=== CONT TestGlobMatch/foo*bar_foo123bar2741=== CONT TestGlobMatch/foo*bar_foobar2742=== CONT TestGlobMatch/*bar_foo2743=== CONT TestGlobMatch/*bar_foobar2744=== CONT TestGlobMatch/foo*_bar2745=== CONT TestGlobMatch/foo*_foobar2746=== CONT TestGlobMatch/foo*_foo2747=== CONT TestGlobMatch/*_anything2748=== CONT TestGlobMatch/*_2749=== CONT TestGlobMatch/foo_bar2750--- PASS: TestGlobMatch (0.00s)2751 --- PASS: TestGlobMatch/foo_foo (0.00s)2752 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2753 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2754 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2755 --- PASS: TestGlobMatch/?oo_boo (0.00s)2756 --- PASS: TestGlobMatch/?oo_foo (0.00s)2757 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2758 --- PASS: TestGlobMatch/fo?_fo (0.00s)2759 --- PASS: TestGlobMatch/fo?_foo (0.00s)2760 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2761 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2762 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2763 --- PASS: TestGlobMatch/*/*_foo (0.00s)2764 --- PASS: TestGlobMatch/*bar_bar (0.00s)2765 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2766 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2767 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2768 --- PASS: TestGlobMatch/*bar_foo (0.00s)2769 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2770 --- PASS: TestGlobMatch/foo*_bar (0.00s)2771 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2772 --- PASS: TestGlobMatch/foo*_foo (0.00s)2773 --- PASS: TestGlobMatch/*_anything (0.00s)2774 --- PASS: TestGlobMatch/*_ (0.00s)2775 --- PASS: TestGlobMatch/foo_bar (0.00s)2776--- PASS: TestValidateToken_Expired (0.06s)27772026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56884/oidc2778--- PASS: TestPins_TopLevelShorthand (0.05s)27792026/09/29 08:18:40 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12327802026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56889/oidc2781--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)2782--- PASS: TestScopes_Rules (0.11s)27832026/09/29 08:18:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56894/oidc2784--- PASS: TestValidateToken_WrongAudience (0.12s)27852026/09/29 08:18:40 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:56887/oidc2786--- PASS: TestValidateToken_NoMatchingProvider (0.12s)27872026/09/29 08:18:40 http: TLS handshake error from 127.0.0.1:56893: remote error: tls: bad certificate2788--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)27892026/09/29 08:18:40 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:568982790--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)27912026/09/29 08:18:40 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:56900/oidc27922026/09/29 08:18:40 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:56886/oidc2793--- PASS: TestValidateToken_MultipleProviders (0.14s)2794PASS2795Running hook tests...2796=== RUN TestSendPathsEmpty2797=== PAUSE TestSendPathsEmpty2798=== RUN TestQueueEnqueueAndFetch2799=== PAUSE TestQueueEnqueueAndFetch2800=== RUN TestQueueDeduplication2801=== PAUSE TestQueueDeduplication2802=== RUN TestQueueRemove2803=== PAUSE TestQueueRemove2804=== RUN TestQueueFetchBatchLimit2805=== PAUSE TestQueueFetchBatchLimit2806=== RUN TestQueueRetryMovesToBack2807=== PAUSE TestQueueRetryMovesToBack2808=== RUN TestQueueFetchRemoveLifecycle2809=== PAUSE TestQueueFetchRemoveLifecycle2810=== RUN TestQueueConcurrentWriters2811=== PAUSE TestQueueConcurrentWriters2812=== RUN TestQueueRemoveLargeClosure2813=== PAUSE TestQueueRemoveLargeClosure2814=== RUN TestServerClientIntegration2815=== PAUSE TestServerClientIntegration2816=== RUN TestServerQueueError2817=== PAUSE TestServerQueueError2818=== RUN TestGetListenerSocketActivation2819 server_test.go:210: === RUN TestGetListenerSocketActivation2820 --- PASS: TestGetListenerSocketActivation (0.00s)2821 PASS2822 2823--- PASS: TestGetListenerSocketActivation (0.01s)2824=== RUN TestDrainIsolatesPoisonPath2825=== PAUSE TestDrainIsolatesPoisonPath2826=== RUN TestRunNotBlockedByPoisonHead2827=== PAUSE TestRunNotBlockedByPoisonHead2828=== RUN TestDrainGivesUpWhenServerDown2829=== PAUSE TestDrainGivesUpWhenServerDown2830=== RUN TestFailedPathPrunedByLaterClosure2831=== PAUSE TestFailedPathPrunedByLaterClosure2832=== RUN TestWorkerUploadsAndRemoves2833=== PAUSE TestWorkerUploadsAndRemoves2834=== RUN TestWorkerSkipsGCdPaths2835=== PAUSE TestWorkerSkipsGCdPaths2836=== RUN TestWorkerPrunesClosureDeps2837=== PAUSE TestWorkerPrunesClosureDeps2838=== RUN TestDrainTimeout2839=== PAUSE TestDrainTimeout2840=== CONT TestSendPathsEmpty2841--- PASS: TestSendPathsEmpty (0.00s)2842=== CONT TestServerClientIntegration2843=== CONT TestServerQueueError2844=== CONT TestWorkerUploadsAndRemoves2845=== CONT TestQueueRetryMovesToBack2846=== CONT TestDrainGivesUpWhenServerDown2847=== CONT TestRunNotBlockedByPoisonHead2848=== CONT TestQueueRemoveLargeClosure2849=== CONT TestQueueRemove2850=== CONT TestQueueDeduplication2851=== CONT TestWorkerPrunesClosureDeps28522026/09/29 08:18:40 ERROR Failed to queue paths error="permission denied" count=12853--- PASS: TestServerClientIntegration (0.00s)2854--- PASS: TestServerQueueError (0.00s)2855=== CONT TestQueueFetchBatchLimit2856=== CONT TestWorkerSkipsGCdPaths28572026/09/29 08:18:40 INFO Upload queue status pending=228582026/09/29 08:18:40 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-9673-972427610/TestWorkerSkipsGCdPaths403606095/002/nonexistent28592026/09/29 08:18:40 INFO Uploading batch count=12860--- PASS: TestQueueRetryMovesToBack (0.00s)2861=== CONT TestDrainIsolatesPoisonPath28622026/09/29 08:18:40 INFO Uploading batch count=228632026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=228642026/09/29 08:18:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9673-972427610/TestDrainGivesUpWhenServerDown4104373736/002/a2865--- PASS: TestQueueFetchBatchLimit (0.00s)2866=== CONT TestQueueEnqueueAndFetch28672026/09/29 08:18:40 INFO Upload queue status pending=328682026/09/29 08:18:40 INFO Uploading batch count=128692026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=128702026/09/29 08:18:40 INFO Upload queue status pending=228712026/09/29 08:18:40 INFO Uploading batch count=128722026/09/29 08:18:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9673-972427610/TestDrainGivesUpWhenServerDown4104373736/002/b2873--- PASS: TestQueueDeduplication (0.00s)2874=== CONT TestQueueConcurrentWriters28752026/09/29 08:18:40 INFO Upload queue status pending=228762026/09/29 08:18:40 INFO Uploading batch count=228772026/09/29 08:18:40 INFO Uploading batch count=228782026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=228792026/09/29 08:18:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9673-972427610/TestDrainGivesUpWhenServerDown4104373736/002/c28802026/09/29 08:18:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9673-972427610/TestDrainGivesUpWhenServerDown4104373736/002/d28812026/09/29 08:18:40 INFO Uploading batch count=228822026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=228832026/09/29 08:18:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9673-972427610/TestDrainGivesUpWhenServerDown4104373736/002/e28842026/09/29 08:18:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9673-972427610/TestDrainGivesUpWhenServerDown4104373736/002/f2885--- PASS: TestQueueRemove (0.01s)2886=== CONT TestFailedPathPrunedByLaterClosure28872026/09/29 08:18:40 ERROR Drain finished with paths left in queue remaining=102888--- PASS: TestQueueEnqueueAndFetch (0.00s)2889=== CONT TestDrainTimeout2890--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2891=== CONT TestQueueFetchRemoveLifecycle28922026/09/29 08:18:40 INFO Uploading batch count=128932026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=128942026/09/29 08:18:40 INFO Uploading batch count=128952026/09/29 08:18:40 INFO Uploading batch count=128962026/09/29 08:18:40 INFO Uploading batch count=428972026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=428982026/09/29 08:18:40 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9673-972427610/TestDrainIsolatesPoisonPath1854199119/002/bbb28992026/09/29 08:18:40 INFO Uploading batch count=129002026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=129012026/09/29 08:18:40 INFO Uploading batch count=229022026/09/29 08:18:40 INFO Uploading batch count=129032026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=129042026/09/29 08:18:40 INFO Uploading batch count=129052026/09/29 08:18:40 ERROR Upload failed error="upload failed" count=12906--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)29072026/09/29 08:18:40 ERROR Drain finished with paths left in queue remaining=12908--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2909--- PASS: TestDrainIsolatesPoisonPath (0.01s)2910--- PASS: TestWorkerSkipsGCdPaths (0.02s)2911--- PASS: TestWorkerUploadsAndRemoves (0.03s)2912--- PASS: TestWorkerPrunesClosureDeps (0.03s)2913--- PASS: TestQueueRemoveLargeClosure (0.04s)2914--- PASS: TestQueueConcurrentWriters (0.09s)29152026/09/29 08:18:40 ERROR Upload failed error="context deadline exceeded" count=229162026/09/29 08:18:40 ERROR Drain finished with paths left in queue remaining=42917--- PASS: TestDrainTimeout (0.21s)29182026/09/29 08:18:41 INFO Uploading batch count=129192026/09/29 08:18:41 INFO Uploading batch count=129202026/09/29 08:18:41 INFO Uploading batch count=129212026/09/29 08:18:41 ERROR Upload failed error="upload failed" count=129222026/09/29 08:18:41 INFO Uploading batch count=129232026/09/29 08:18:41 ERROR Upload failed error="upload failed" count=129242026/09/29 08:18:41 INFO Uploading batch count=129252026/09/29 08:18:41 ERROR Upload failed error="upload failed" count=129262026/09/29 08:18:41 INFO Uploading batch count=129272026/09/29 08:18:41 ERROR Upload failed error="upload failed" count=129282026/09/29 08:18:41 ERROR Drain finished with paths left in queue remaining=12929--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2930PASS