niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #301
· 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 TestShellSplit95=== CONT TestDoServerRequestAttachesToken96--- PASS: TestShellSplit (0.00s)97=== CONT TestGetStorePathHash98=== RUN TestGetStorePathHash/valid_store_path99=== PAUSE TestGetStorePathHash/valid_store_path100=== RUN TestGetStorePathHash/basename_without_hyphen_should_error101=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error102=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error103=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error104=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error105=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error106=== CONT TestConvertHashToNix32107=== RUN TestConvertHashToNix32/SRI_format_to_Nix32108=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32109=== RUN TestConvertHashToNix32/already_Nix32_format110=== PAUSE TestConvertHashToNix32/already_Nix32_format111=== RUN TestConvertHashToNix32/invalid_format112=== PAUSE TestConvertHashToNix32/invalid_format113=== CONT TestEncodeNixBase32WithRealHash114=== CONT TestDoWithRetry_BodyReplayedViaGetBody115=== CONT TestResolveStorePath116=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1172026/10/01 08:26:45 WARN Rate limiter enabled after throttle name=server-test rate=5118=== CONT TestRateLimiterFeedback119=== RUN TestRateLimiterFeedback/429_enables_limiter120=== PAUSE TestRateLimiterFeedback/429_enables_limiter121=== RUN TestRateLimiterFeedback/503_enables_limiter122=== PAUSE TestRateLimiterFeedback/503_enables_limiter123=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter124=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter125=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter126=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter127=== CONT TestDumpPathWriterError128=== CONT TestPathInfoCACompatibility129=== RUN TestPathInfoCACompatibility/null_ca_field130=== CONT TestParsePathInfoJSONMultiplePaths131=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths132=== CONT TestParsePathInfoJSON133=== CONT TestPathInfoHashCompatibility134=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths135=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)136--- PASS: TestEncodeNixBase32WithRealHash (0.00s)137=== CONT TestEncodeNixBase32138=== PAUSE TestPathInfoCACompatibility/null_ca_field139=== RUN TestParsePathInfoJSON/Nix_format140=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)141=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon142=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths143--- PASS: TestResolveStorePath (0.00s)144=== RUN TestEncodeNixBase32/test_string_hash145=== RUN TestPathInfoCACompatibility/old_string_format_-_text146=== PAUSE TestParsePathInfoJSON/Nix_format147=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text148=== RUN TestParsePathInfoJSON/Lix_format149=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive150=== PAUSE TestParsePathInfoJSON/Lix_format151=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive152=== RUN TestParsePathInfoJSON/empty_input153=== RUN TestPathInfoCACompatibility/new_structured_format_-_text154=== PAUSE TestParsePathInfoJSON/empty_input155=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text156=== RUN TestParsePathInfoJSON/whitespace_only157=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method158=== PAUSE TestEncodeNixBase32/test_string_hash159=== RUN TestEncodeNixBase32/empty_input160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon161=== PAUSE TestParsePathInfoJSON/whitespace_only162=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method163=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI164=== CONT TestDumpPathMatchesNix165=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI166=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512167=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512168=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths169=== CONT TestDumpPathSingleFile170=== CONT TestPartSizeForNAR1712026/10/01 08:26:45 WARN Rate limiter enabled after throttle name=server-test rate=51722026/10/01 08:26:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59785173=== RUN TestPartSizeForNAR/zero_stays_at_minimum174=== PAUSE TestEncodeNixBase32/empty_input175=== RUN TestParsePathInfoJSON/invalid_JSON176=== PAUSE TestParsePathInfoJSON/invalid_JSON177=== CONT TestUploadMultipart_PartsInParallel178=== CONT TestUploadMultipart_SupersededByPeer179=== RUN TestUploadMultipart_SupersededByPeer/exists180=== CONT TestFilterOversizedClosures181=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum182=== RUN TestFilterOversizedClosures/no_limit_keeps_everything183=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything184=== RUN TestPartSizeForNAR/small_stays_at_minimum185=== PAUSE TestPartSizeForNAR/small_stays_at_minimum186=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped187=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum188=== PAUSE TestUploadMultipart_SupersededByPeer/exists189=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped190=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum191=== RUN TestFilterOversizedClosures/all_closures_skipped192=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts193=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts194=== PAUSE TestFilterOversizedClosures/all_closures_skipped195=== RUN TestUploadMultipart_SupersededByPeer/missing196=== PAUSE TestUploadMultipart_SupersededByPeer/missing197=== CONT TestCaseHackSuffix198=== RUN TestPartSizeForNAR/1_TiB199=== PAUSE TestPartSizeForNAR/1_TiB200=== RUN TestPartSizeForNAR/5_TiB_S3_max_object2012026/10/01 08:26:45 WARN Rate limiter backed off name=server-test rate=5202=== CONT TestRegisterUploadedObjectReusesConnections2032026/10/01 08:26:45 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59785204=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object205=== RUN TestPartSizeForNAR/capped_at_5_GiB206=== PAUSE TestPartSizeForNAR/capped_at_5_GiB207=== CONT TestSetClientTLSErrors208--- PASS: TestDoServerRequestAttachesToken (0.01s)209=== CONT TestScriptTokenEmptyCommand210--- PASS: TestScriptTokenEmptyCommand (0.00s)211=== CONT TestScriptTokenScriptFails212--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)213=== CONT TestScriptTokenBadJSON214=== RUN TestSetClientTLSErrors/missing_cert_file215=== PAUSE TestSetClientTLSErrors/missing_cert_file216=== RUN TestSetClientTLSErrors/missing_key_file217=== PAUSE TestSetClientTLSErrors/missing_key_file218=== RUN TestSetClientTLSErrors/missing_ca_file219=== PAUSE TestSetClientTLSErrors/missing_ca_file220=== RUN TestSetClientTLSErrors/invalid_ca_file221=== PAUSE TestSetClientTLSErrors/invalid_ca_file222=== CONT TestScriptTokenEmptyToken223--- PASS: TestScriptTokenScriptFails (0.01s)224=== CONT TestScriptTokenCachesUntilRefresh225--- PASS: TestScriptTokenBadJSON (0.02s)226=== CONT TestScriptTokenNoExpiryRerunsEveryCall227--- PASS: TestScriptTokenEmptyToken (0.02s)228=== CONT TestFileTokenEmpty229--- PASS: TestFileTokenEmpty (0.00s)230=== CONT TestFileTokenMissing231--- PASS: TestFileTokenMissing (0.00s)232=== CONT TestFileTokenReadsAndCaches233--- PASS: TestFileTokenReadsAndCaches (0.00s)234=== CONT TestStaticToken235--- PASS: TestStaticToken (0.00s)236=== CONT TestStreamPushRequestLine2372026/10/01 08:26:45 ERROR Upload failed error=boom count=1238--- PASS: TestStreamPushRequestLine (0.01s)239=== CONT TestSetClientTLSDoesNotMutateDefaultTransport240--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)241=== CONT TestSetClientTLS242=== RUN TestSetClientTLS/rejects_connection_without_client_cert243=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert244=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA245=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA246=== RUN TestSetClientTLS/preserves_debug_logging_transport247=== PAUSE TestSetClientTLS/preserves_debug_logging_transport248=== CONT TestClientSignaturesByStorePath249--- PASS: TestClientSignaturesByStorePath (0.00s)250=== CONT TestStreamPushReportsSignatures2512026/10/01 08:26:45 ERROR Upload failed error=boom count=1252--- PASS: TestStreamPushReportsSignatures (0.00s)253=== CONT TestStreamPushBatchesUnderLoad254--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)255=== CONT TestStreamPushGivesUpOnDeadServer2562026/10/01 08:26:45 ERROR Upload failed error="connection refused" count=202572026/10/01 08:26:45 ERROR Server seems unavailable, giving up on batch untried=17258--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)259=== CONT TestStreamPushIsolatesFailures2602026/10/01 08:26:45 ERROR Upload failed error="bad path" count=3261--- PASS: TestStreamPushIsolatesFailures (0.00s)262=== CONT TestStreamPushReportsEveryPath263--- PASS: TestStreamPushReportsEveryPath (0.00s)264=== CONT TestShellSplitErrors265--- PASS: TestShellSplitErrors (0.00s)266=== CONT TestGetStorePathHash/valid_store_path267=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error268=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error269=== CONT TestGetStorePathHash/basename_without_hyphen_should_error270--- PASS: TestGetStorePathHash (0.00s)271 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)272 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)273 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)274 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)275=== CONT TestConvertHashToNix32/SRI_format_to_Nix32276=== CONT TestConvertHashToNix32/invalid_format277=== CONT TestConvertHashToNix32/already_Nix32_format278--- PASS: TestConvertHashToNix32 (0.00s)279 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)280 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)281 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)282=== CONT TestRateLimiterFeedback/429_enables_limiter2832026/10/01 08:26:45 WARN Rate limiter enabled after throttle name=server-test rate=52842026/10/01 08:26:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:598612852026/10/01 08:26:45 WARN Rate limiter backed off name=server-test rate=5286=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter287=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter288=== CONT TestRateLimiterFeedback/503_enables_limiter2892026/10/01 08:26:45 WARN Rate limiter enabled after throttle name=server-test rate=52902026/10/01 08:26:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:598672912026/10/01 08:26:45 WARN Rate limiter backed off name=server-test rate=5292--- PASS: TestRateLimiterFeedback (0.00s)293 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)294 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)295 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)296 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)297=== CONT TestPathInfoCACompatibility/null_ca_field298=== CONT TestPathInfoCACompatibility/new_structured_format_-_text299=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive300=== CONT TestPathInfoCACompatibility/old_string_format_-_text301=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method302--- PASS: TestPathInfoCACompatibility (0.00s)303 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)304 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)305 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)306 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)307 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)308=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)309=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512310=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI311=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon312--- PASS: TestPathInfoHashCompatibility (0.00s)313 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)314 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)315 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)316 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)317=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths318=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths319--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)320 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)321 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)322=== CONT TestEncodeNixBase32/test_string_hash323=== CONT TestParsePathInfoJSON/Nix_format324=== CONT TestParsePathInfoJSON/invalid_JSON325=== CONT TestEncodeNixBase32/empty_input326--- PASS: TestEncodeNixBase32 (0.00s)327 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)328 --- PASS: TestEncodeNixBase32/empty_input (0.00s)329=== CONT TestParsePathInfoJSON/empty_input330=== CONT TestParsePathInfoJSON/whitespace_only331=== CONT TestParsePathInfoJSON/Lix_format332--- PASS: TestParsePathInfoJSON (0.00s)333 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)334 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)335 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)336 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)337 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)338=== CONT TestFilterOversizedClosures/no_limit_keeps_everything339=== CONT TestUploadMultipart_SupersededByPeer/exists340=== CONT TestUploadMultipart_SupersededByPeer/missing341--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)342 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)343 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)344=== CONT TestFilterOversizedClosures/all_closures_skipped3452026/10/01 08:26:45 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=50346=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3472026/10/01 08:26:45 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=2000348--- PASS: TestFilterOversizedClosures (0.00s)349 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)350 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)351 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)352=== CONT TestPartSizeForNAR/zero_stays_at_minimum353=== CONT TestPartSizeForNAR/1_TiB354=== CONT TestPartSizeForNAR/capped_at_5_GiB355=== CONT TestPartSizeForNAR/5_TiB_S3_max_object356=== CONT TestSetClientTLSErrors/missing_cert_file357=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts358=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum359=== CONT TestPartSizeForNAR/small_stays_at_minimum360--- PASS: TestPartSizeForNAR (0.00s)361 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)365 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)366 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)368=== CONT TestSetClientTLSErrors/missing_ca_file369=== CONT TestSetClientTLSErrors/invalid_ca_file370=== CONT TestSetClientTLSErrors/missing_key_file371=== CONT TestSetClientTLS/rejects_connection_without_client_cert372--- PASS: TestSetClientTLSErrors (0.01s)373 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)374 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)375 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)376 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)377--- PASS: TestDumpPathWriterError (0.06s)378=== CONT TestSetClientTLS/preserves_debug_logging_transport379--- PASS: TestDumpPathSingleFile (0.06s)380=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA381--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)382--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)3832026/10/01 08:26:45 http: TLS handshake error from 127.0.0.1:59873: remote error: tls: bad certificate384--- PASS: TestSetClientTLS (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)387 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)388--- PASS: TestCaseHackSuffix (0.06s)389--- PASS: TestDumpPathMatchesNix (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.62s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".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-86274-2014532869/postgres992439558/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-86274-2014532869/postgres992439558/data -l logfile start421422/nix/var/nix/builds/nix-86274-2014532869/postgres992439558:5432 - no response4232026-10-01 08:26:47.464 UTC [86329] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 08:26:47.465 UTC [86329] LOG: listening on Unix socket "/nix/var/nix/builds/nix-86274-2014532869/postgres992439558/.s.PGSQL.5432"4252026-10-01 08:26:47.467 UTC [86336] LOG: database system was shut down at 2026-10-01 08:26:47 UTC4262026-10-01 08:26:47.468 UTC [86329] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-86274-2014532869/postgres992439558:5432 - accepting connections428{"timestamp":"2026-10-01T08:26:47.682911Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"51a89e8a-9bcb-4411-aeb9-cd1f4fabb078","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(7)"}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-10-01 08:26:47.943 UTC [86366] ERROR: relation "goose_db_version" does not exist at character 364712026-10-01 08:26:47.943 UTC [86366] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/10/01 08:26:47 OK 20241026095416_initial_model.sql (4.12ms)4732026/10/01 08:26:47 OK 20251210153512_drop_unused_gin_index.sql (459.42µs)4742026/10/01 08:26:47 OK 20251218171726_add_pins.sql (949.67µs)4752026/10/01 08:26:47 OK 20260628120000_add_object_size_and_stats.sql (931.88µs)4762026/10/01 08:26:47 OK 20260905000000_add_claims.sql (1.07ms)4772026/10/01 08:26:47 OK 20260920000000_drop_claims.sql (661.42µs)4782026/10/01 08:26:47 OK 20260923120000_add_pushes.sql (405µs)4792026/10/01 08:26:47 goose: successfully migrated database to version: 202609231200004802026/10/01 08:26:47 OK 1_commit_pending_closure.sql (985.29µs)4812026/10/01 08:26:47 OK 2_object_stats_trigger.sql (206.21µs)4822026/10/01 08:26:47 OK 3_commit_push.sql (183.04µs)4832026/10/01 08:26:47 goose: up to current file version: 34842026/10/01 08:26:48 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 08:26:48 INFO lead: released remote=192.0.2.1:12344862026/10/01 08:26:48 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 08:26:48 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.88s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-10-01 08:26:48.758 UTC [86370] ERROR: relation "goose_db_version" does not exist at character 364932026-10-01 08:26:48.758 UTC [86370] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/10/01 08:26:48 OK 20241026095416_initial_model.sql (3.68ms)4952026/10/01 08:26:48 OK 20251210153512_drop_unused_gin_index.sql (482.88µs)4962026/10/01 08:26:48 OK 20251218171726_add_pins.sql (849.33µs)4972026/10/01 08:26:48 OK 20260628120000_add_object_size_and_stats.sql (823.17µs)4982026/10/01 08:26:48 OK 20260905000000_add_claims.sql (1.01ms)4992026/10/01 08:26:48 OK 20260920000000_drop_claims.sql (620.5µs)5002026/10/01 08:26:48 OK 20260923120000_add_pushes.sql (424.46µs)5012026/10/01 08:26:48 goose: successfully migrated database to version: 202609231200005022026/10/01 08:26:48 OK 1_commit_pending_closure.sql (876.63µs)5032026/10/01 08:26:48 OK 2_object_stats_trigger.sql (214.96µs)5042026/10/01 08:26:48 OK 3_commit_push.sql (187.42µs)5052026/10/01 08:26:48 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestObjectStatsTrigger578=== PAUSE TestObjectStatsTrigger579=== RUN TestOrphanedObjectsGC580=== PAUSE TestOrphanedObjectsGC581=== RUN TestOrphanedObjectsGCStressTest582=== PAUSE TestOrphanedObjectsGCStressTest583=== RUN TestCreatePin_ReservedPins584=== PAUSE TestCreatePin_ReservedPins585=== RUN TestParseSingleRange586=== PAUSE TestParseSingleRange587=== RUN TestProxyHeadersOnlyTrustedOnSocket588=== PAUSE TestProxyHeadersOnlyTrustedOnSocket589=== RUN TestIsValidCachePath590=== PAUSE TestIsValidCachePath591=== RUN TestReadProxyNarinfo592=== PAUSE TestReadProxyNarinfo593=== RUN TestReadProxyNarinfoAlreadyDecompressed594=== PAUSE TestReadProxyNarinfoAlreadyDecompressed595=== RUN TestReadProxyNarStreaming596=== PAUSE TestReadProxyNarStreaming597=== RUN TestReadProxy404598=== PAUSE TestReadProxy404599=== RUN TestReadProxyInvalidPath600=== PAUSE TestReadProxyInvalidPath601=== RUN TestReadProxyHead602=== PAUSE TestReadProxyHead603=== RUN TestReadProxyConditionalGet604=== PAUSE TestReadProxyConditionalGet605=== RUN TestReadProxyRootRedirectsToIndexHTML606=== PAUSE TestReadProxyRootRedirectsToIndexHTML607=== RUN TestReadProxyDisabled608=== PAUSE TestReadProxyDisabled609=== RUN TestReadRedirectNar610=== PAUSE TestReadRedirectNar611=== RUN TestReadRedirectKeepsNarinfoProxied612=== PAUSE TestReadRedirectKeepsNarinfoProxied613=== RUN TestReadProxyRangeRequest614=== PAUSE TestReadProxyRangeRequest615=== RUN TestReadRedirectUsesPublicS3URL616=== PAUSE TestReadRedirectUsesPublicS3URL617=== RUN TestPush_OverlappingRootsStoreOneRowPerKey618=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey619=== RUN TestPush_CompleteCommitsEveryRoot620=== PAUSE TestPush_CompleteCommitsEveryRoot621=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit622=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit623=== RUN TestPush_RejectsBadRequests624=== PAUSE TestPush_RejectsBadRequests625=== RUN TestPush_SignsNarinfosOfItsPendingObjects626=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects627=== RUN TestRedundantMultipartUpload628=== PAUSE TestRedundantMultipartUpload629=== RUN TestCompleteMultipartUpload_ErrorButObjectExists630=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists631=== RUN TestCompletedNarNotReofferedAcrossClosures632=== PAUSE TestCompletedNarNotReofferedAcrossClosures633=== RUN TestPresignedUploadRegisteredBeforeCommit634=== PAUSE TestPresignedUploadRegisteredBeforeCommit635=== RUN TestService_Rustfstest636=== PAUSE TestService_Rustfstest637=== RUN TestParseSize638=== PAUSE TestParseSize639=== RUN TestSkippedUploadsHandler640=== PAUSE TestSkippedUploadsHandler641=== RUN TestSystemdListenerNotActivated642--- PASS: TestSystemdListenerNotActivated (0.00s)643=== RUN TestWatchdogBeatsWhenHealthy644--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)645=== RUN TestWatchdogSkipsWhenUnhealthy6462026/10/01 08:26:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 08:26:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 08:26:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 08:26:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 08:26:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 08:26:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 08:26:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/01 08:26:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6542026/10/01 08:26:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"655--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)656=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle657=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle658=== RUN TestProxyWriteTimeout659=== PAUSE TestProxyWriteTimeout660=== RUN TestIsValidUploadKey661=== PAUSE TestIsValidUploadKey662=== RUN TestUploadHandlersRejectInvalidKeys663=== PAUSE TestUploadHandlersRejectInvalidKeys664=== RUN TestUploadHandlersRejectOversizedBody665=== PAUSE TestUploadHandlersRejectOversizedBody666=== RUN TestService_cleanupPendingClosuresHandler667=== PAUSE TestService_cleanupPendingClosuresHandler668=== RUN TestService_createPendingClosureHandler669=== PAUSE TestService_createPendingClosureHandler670=== RUN TestService_verifyS3Integrity671=== PAUSE TestService_verifyS3Integrity672=== RUN TestCompleteMultipartUnregistered673=== PAUSE TestCompleteMultipartUnregistered674=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT675=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT676=== CONT TestReadProxy404677=== CONT TestCreatePin_ReservedPins678=== CONT TestCompleteMultipartUpload_ErrorButObjectExists679=== CONT TestReadProxyNarStreaming680=== CONT TestReadProxyNarinfoAlreadyDecompressed681=== CONT TestReadProxyNarinfo682=== CONT TestIsValidCachePath683=== CONT TestProxyHeadersOnlyTrustedOnSocket684=== CONT TestParseSingleRange685=== RUN TestParseSingleRange/none686=== CONT TestService_AuthMiddleware687=== PAUSE TestParseSingleRange/none688=== RUN TestParseSingleRange/unknown_unit689=== PAUSE TestParseSingleRange/unknown_unit690=== RUN TestIsValidCachePath/narinfo691=== RUN TestParseSingleRange/multi-range_ignored692=== PAUSE TestIsValidCachePath/narinfo693=== PAUSE TestParseSingleRange/multi-range_ignored694=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars695=== RUN TestParseSingleRange/malformed_no_dash696=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars697=== RUN TestIsValidCachePath/nar_zst698=== PAUSE TestParseSingleRange/malformed_no_dash699=== RUN TestParseSingleRange/malformed_both_empty700=== PAUSE TestParseSingleRange/malformed_both_empty701=== RUN TestParseSingleRange/malformed_end_before_start702=== PAUSE TestParseSingleRange/malformed_end_before_start703=== RUN TestParseSingleRange/closed704=== PAUSE TestParseSingleRange/closed705=== RUN TestParseSingleRange/open-ended706=== PAUSE TestParseSingleRange/open-ended707=== RUN TestParseSingleRange/end_clamped_to_size708=== PAUSE TestParseSingleRange/end_clamped_to_size709=== RUN TestParseSingleRange/suffix710=== PAUSE TestIsValidCachePath/nar_zst711=== PAUSE TestParseSingleRange/suffix712=== RUN TestParseSingleRange/suffix_exceeds_size713=== PAUSE TestParseSingleRange/suffix_exceeds_size714=== RUN TestIsValidCachePath/nar_xz715=== PAUSE TestIsValidCachePath/nar_xz716=== RUN TestParseSingleRange/single_byte717=== PAUSE TestParseSingleRange/single_byte718=== RUN TestParseSingleRange/start_past_EOF719=== PAUSE TestParseSingleRange/start_past_EOF720=== RUN TestIsValidCachePath/nar_bz2721=== PAUSE TestIsValidCachePath/nar_bz2722=== RUN TestParseSingleRange/start_far_past_EOF723=== PAUSE TestParseSingleRange/start_far_past_EOF724=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT725=== RUN TestIsValidCachePath/nar_uncompressed726=== PAUSE TestIsValidCachePath/nar_uncompressed727=== RUN TestIsValidCachePath/ls728=== PAUSE TestIsValidCachePath/ls729=== RUN TestIsValidCachePath/log730=== PAUSE TestIsValidCachePath/log731=== RUN TestIsValidCachePath/realisation732=== PAUSE TestIsValidCachePath/realisation733=== RUN TestIsValidCachePath/nix-cache-info734=== PAUSE TestIsValidCachePath/nix-cache-info735=== RUN TestIsValidCachePath/index.html736=== PAUSE TestIsValidCachePath/index.html737=== RUN TestIsValidCachePath/traversal_parent738=== PAUSE TestIsValidCachePath/traversal_parent739=== RUN TestIsValidCachePath/traversal_in_middle740=== PAUSE TestIsValidCachePath/traversal_in_middle741=== RUN TestIsValidCachePath/invalid_char_e742=== PAUSE TestIsValidCachePath/invalid_char_e743=== RUN TestIsValidCachePath/invalid_char_u744=== PAUSE TestIsValidCachePath/invalid_char_u745=== RUN TestIsValidCachePath/random_path746=== PAUSE TestIsValidCachePath/random_path747=== RUN TestIsValidCachePath/empty748=== PAUSE TestIsValidCachePath/empty749=== RUN TestIsValidCachePath/leading_slash750=== PAUSE TestIsValidCachePath/leading_slash751=== RUN TestIsValidCachePath/wrong_extension752=== PAUSE TestIsValidCachePath/wrong_extension753=== RUN TestIsValidCachePath/short_hash754=== PAUSE TestIsValidCachePath/short_hash755=== CONT TestCompleteMultipartUnregistered7562026/10/01 08:26:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59893/oidc7572026-10-01 08:26:49.385 UTC [86392] ERROR: relation "goose_db_version" does not exist at character 367582026-10-01 08:26:49.385 UTC [86392] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026-10-01 08:26:49.386 UTC [86395] ERROR: relation "goose_db_version" does not exist at character 367602026-10-01 08:26:49.386 UTC [86395] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7612026-10-01 08:26:49.386 UTC [86394] ERROR: relation "goose_db_version" does not exist at character 367622026-10-01 08:26:49.386 UTC [86394] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026-10-01 08:26:49.386 UTC [86393] ERROR: relation "goose_db_version" does not exist at character 367642026-10-01 08:26:49.386 UTC [86393] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026-10-01 08:26:49.386 UTC [86396] ERROR: relation "goose_db_version" does not exist at character 367662026-10-01 08:26:49.386 UTC [86396] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7672026-10-01 08:26:49.387 UTC [86398] ERROR: relation "goose_db_version" does not exist at character 367682026-10-01 08:26:49.387 UTC [86398] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7692026-10-01 08:26:49.389 UTC [86397] ERROR: relation "goose_db_version" does not exist at character 367702026-10-01 08:26:49.389 UTC [86397] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026-10-01 08:26:49.389 UTC [86400] ERROR: relation "goose_db_version" does not exist at character 367722026-10-01 08:26:49.389 UTC [86400] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026-10-01 08:26:49.389 UTC [86399] ERROR: relation "goose_db_version" does not exist at character 367742026-10-01 08:26:49.389 UTC [86399] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026-10-01 08:26:49.391 UTC [86401] ERROR: relation "goose_db_version" does not exist at character 367762026-10-01 08:26:49.391 UTC [86401] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026/10/01 08:26:49 OK 20241026095416_initial_model.sql (7.23ms)7782026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)7792026/10/01 08:26:49 OK 20241026095416_initial_model.sql (8.43ms)7802026/10/01 08:26:49 OK 20241026095416_initial_model.sql (9.03ms)7812026/10/01 08:26:49 OK 20241026095416_initial_model.sql (8.99ms)7822026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (584.96µs)7832026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (421.13µs)7842026/10/01 08:26:49 OK 20251218171726_add_pins.sql (1.15ms)7852026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (714.92µs)7862026/10/01 08:26:49 OK 20241026095416_initial_model.sql (6.72ms)7872026/10/01 08:26:49 OK 20241026095416_initial_model.sql (7.09ms)7882026/10/01 08:26:49 OK 20241026095416_initial_model.sql (9.98ms)7892026/10/01 08:26:49 OK 20251218171726_add_pins.sql (3.71ms)7902026/10/01 08:26:49 OK 20251218171726_add_pins.sql (1.94ms)7912026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (1.33ms)7922026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (757.29µs)7932026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (918.46µs)7942026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)7952026/10/01 08:26:49 OK 20241026095416_initial_model.sql (8ms)7962026/10/01 08:26:49 OK 20241026095416_initial_model.sql (10.61ms)7972026/10/01 08:26:49 OK 20251218171726_add_pins.sql (1.9ms)7982026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (1.38ms)7992026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (765.29µs)8002026/10/01 08:26:49 OK 20251218171726_add_pins.sql (1.62ms)8012026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)8022026/10/01 08:26:49 OK 20251218171726_add_pins.sql (1.73ms)8032026/10/01 08:26:49 OK 20260905000000_add_claims.sql (2.11ms)8042026/10/01 08:26:49 OK 20251218171726_add_pins.sql (2.01ms)8052026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)8062026/10/01 08:26:49 OK 20260905000000_add_claims.sql (1.65ms)8072026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (2.21ms)8082026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.44ms)8092026/10/01 08:26:49 OK 20241026095416_initial_model.sql (10.32ms)8102026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (1.77ms)8112026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (2.14ms)8122026/10/01 08:26:49 OK 20251218171726_add_pins.sql (2.27ms)8132026/10/01 08:26:49 OK 20251218171726_add_pins.sql (2.12ms)8142026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (1.79ms)8152026/10/01 08:26:49 OK 20251210153512_drop_unused_gin_index.sql (836.88µs)8162026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (1.05ms)8172026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008182026/10/01 08:26:49 OK 20260905000000_add_claims.sql (1.75ms)8192026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (2.05ms)8202026/10/01 08:26:49 OK 20260905000000_add_claims.sql (2.82ms)8212026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.45ms)8222026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (2.37ms)8232026/10/01 08:26:49 OK 20260905000000_add_claims.sql (2.53ms)8242026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (1.47ms)8252026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008262026/10/01 08:26:49 OK 1_commit_pending_closure.sql (1.8ms)8272026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.35ms)8282026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (2.73ms)8292026/10/01 08:26:49 OK 20251218171726_add_pins.sql (2.11ms)8302026/10/01 08:26:49 OK 20260905000000_add_claims.sql (2.89ms)8312026/10/01 08:26:49 OK 20260905000000_add_claims.sql (2.74ms)8322026/10/01 08:26:49 OK 2_object_stats_trigger.sql (370.25µs)8332026/10/01 08:26:49 OK 3_commit_push.sql (565.88µs)8342026/10/01 08:26:49 goose: up to current file version: 38352026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (1.36ms)8362026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008372026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.28ms)8382026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (1.09ms)8392026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008402026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.02ms)8412026/10/01 08:26:49 OK 1_commit_pending_closure.sql (1.49ms)8422026/10/01 08:26:49 OK 2_object_stats_trigger.sql (242.33µs)8432026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.57ms)8442026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (871µs)8452026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008462026/10/01 08:26:49 OK 20260905000000_add_claims.sql (2.34ms)8472026/10/01 08:26:49 OK 3_commit_push.sql (572.58µs)8482026/10/01 08:26:49 goose: up to current file version: 38492026/10/01 08:26:49 OK 20260628120000_add_object_size_and_stats.sql (2ms)8502026/10/01 08:26:49 OK 20260905000000_add_claims.sql (2.07ms)8512026/10/01 08:26:49 OK 1_commit_pending_closure.sql (1.18ms)8522026/10/01 08:26:49 OK 1_commit_pending_closure.sql (1.33ms)8532026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (1.26ms)8542026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008552026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (647.75µs)8562026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008572026/10/01 08:26:49 OK 2_object_stats_trigger.sql (270.75µs)8582026/10/01 08:26:49 OK 2_object_stats_trigger.sql (323.46µs)8592026/10/01 08:26:49 OK 3_commit_push.sql (256.13µs)8602026/10/01 08:26:49 goose: up to current file version: 38612026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.16ms)8622026/10/01 08:26:49 OK 1_commit_pending_closure.sql (1.21ms)8632026/10/01 08:26:49 OK 3_commit_push.sql (506.42µs)8642026/10/01 08:26:49 goose: up to current file version: 38652026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (1.1ms)8662026/10/01 08:26:49 OK 1_commit_pending_closure.sql (1.08ms)8672026/10/01 08:26:49 OK 2_object_stats_trigger.sql (514.42µs)8682026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (555.04µs)8692026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008702026/10/01 08:26:49 OK 1_commit_pending_closure.sql (1.34ms)8712026/10/01 08:26:49 OK 2_object_stats_trigger.sql (316.83µs)8722026/10/01 08:26:49 OK 20260905000000_add_claims.sql (1.84ms)8732026/10/01 08:26:49 OK 3_commit_push.sql (274.79µs)8742026/10/01 08:26:49 goose: up to current file version: 38752026/10/01 08:26:49 OK 2_object_stats_trigger.sql (233.58µs)8762026/10/01 08:26:49 OK 3_commit_push.sql (196.92µs)8772026/10/01 08:26:49 goose: up to current file version: 38782026/10/01 08:26:49 OK 3_commit_push.sql (132.96µs)8792026/10/01 08:26:49 goose: up to current file version: 38802026/10/01 08:26:49 OK 1_commit_pending_closure.sql (706.25µs)8812026/10/01 08:26:49 OK 2_object_stats_trigger.sql (179.38µs)8822026/10/01 08:26:49 OK 3_commit_push.sql (175.33µs)8832026/10/01 08:26:49 goose: up to current file version: 38842026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (11.61ms)8852026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008862026/10/01 08:26:49 OK 20260920000000_drop_claims.sql (11.26ms)8872026/10/01 08:26:49 OK 1_commit_pending_closure.sql (733.25µs)8882026/10/01 08:26:49 OK 20260923120000_add_pushes.sql (443.5µs)8892026/10/01 08:26:49 goose: successfully migrated database to version: 202609231200008902026/10/01 08:26:49 OK 2_object_stats_trigger.sql (223.54µs)8912026/10/01 08:26:49 OK 3_commit_push.sql (152.42µs)8922026/10/01 08:26:49 goose: up to current file version: 38932026/10/01 08:26:49 OK 1_commit_pending_closure.sql (748µs)8942026/10/01 08:26:49 OK 2_object_stats_trigger.sql (192µs)8952026/10/01 08:26:49 OK 3_commit_push.sql (164.21µs)8962026/10/01 08:26:49 goose: up to current file version: 3897--- PASS: TestReadProxyNarinfo (0.49s)898=== CONT TestService_verifyS3Integrity8992026/10/01 08:26:49 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"900--- PASS: TestService_AuthMiddleware (0.60s)901=== CONT TestService_createPendingClosureHandler902--- PASS: TestReadProxy404 (0.76s)903=== CONT TestService_cleanupPendingClosuresHandler9042026/10/01 08:26:50 INFO Starting HTTP server address=127.0.0.1:599079052026/10/01 08:26:50 INFO Starting HTTP server address=/nix/var/nix/builds/nix-86274-2014532869/TestProxyHeadersOnlyTrustedOnSocket2311989925/001/proxy.sock9062026/10/01 08:26:50 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9072026/10/01 08:26:50 INFO Shutdown signal received, draining in-flight requests timeout=10s908--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.96s)909=== CONT TestUploadHandlersRejectOversizedBody910=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure911=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure912=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart913=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart914=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts915=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts916=== CONT TestUploadHandlersRejectInvalidKeys917=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info918=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info919=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal920=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal921=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key922=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key923=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key924=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key925=== CONT TestIsValidUploadKey926=== RUN TestIsValidUploadKey/narinfo927=== PAUSE TestIsValidUploadKey/narinfo928=== RUN TestIsValidUploadKey/nar_zst929=== PAUSE TestIsValidUploadKey/nar_zst930=== RUN TestIsValidUploadKey/nar_xz931=== PAUSE TestIsValidUploadKey/nar_xz932=== RUN TestIsValidUploadKey/nar_plain933=== PAUSE TestIsValidUploadKey/nar_plain934=== RUN TestIsValidUploadKey/listing935=== PAUSE TestIsValidUploadKey/listing936=== RUN TestIsValidUploadKey/build_log937=== PAUSE TestIsValidUploadKey/build_log938=== RUN TestIsValidUploadKey/build_log_home-manager_file939=== PAUSE TestIsValidUploadKey/build_log_home-manager_file940=== RUN TestIsValidUploadKey/build_log_plus_in_name941=== PAUSE TestIsValidUploadKey/build_log_plus_in_name942=== RUN TestIsValidUploadKey/build_log_question_mark943=== PAUSE TestIsValidUploadKey/build_log_question_mark944=== RUN TestIsValidUploadKey/build_log_equals945=== PAUSE TestIsValidUploadKey/build_log_equals946=== RUN TestIsValidUploadKey/realisation947=== PAUSE TestIsValidUploadKey/realisation948=== RUN TestIsValidUploadKey/realisation_plus_in_output949=== PAUSE TestIsValidUploadKey/realisation_plus_in_output950=== RUN TestIsValidUploadKey/nix-cache-info951=== PAUSE TestIsValidUploadKey/nix-cache-info952=== RUN TestIsValidUploadKey/index.html953=== PAUSE TestIsValidUploadKey/index.html954=== RUN TestIsValidUploadKey/narinfo_key,_nar_type955=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type956=== RUN TestIsValidUploadKey/nar_key,_narinfo_type957=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type958=== RUN TestIsValidUploadKey/listing_key,_narinfo_type959=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type960=== RUN TestIsValidUploadKey/traversal961=== PAUSE TestIsValidUploadKey/traversal962=== RUN TestIsValidUploadKey/traversal_nar963=== PAUSE TestIsValidUploadKey/traversal_nar964=== RUN TestIsValidUploadKey/absolute965=== PAUSE TestIsValidUploadKey/absolute966=== RUN TestIsValidUploadKey/empty_key967=== PAUSE TestIsValidUploadKey/empty_key968=== RUN TestIsValidUploadKey/unknown_type969=== PAUSE TestIsValidUploadKey/unknown_type970=== CONT TestProxyWriteTimeout971=== RUN TestProxyWriteTimeout/narinfo972=== PAUSE TestProxyWriteTimeout/narinfo973=== RUN TestProxyWriteTimeout/1_GiB_nar974=== PAUSE TestProxyWriteTimeout/1_GiB_nar975=== RUN TestProxyWriteTimeout/10_GiB_nar976=== PAUSE TestProxyWriteTimeout/10_GiB_nar977=== RUN TestProxyWriteTimeout/unknown_size978=== PAUSE TestProxyWriteTimeout/unknown_size979=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9802026/10/01 08:26:50 INFO Received uploads request method=POST path=/api/pending_closures9812026/10/01 08:26:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9822026/10/01 08:26:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjJjNDI4MDktNjNlMi00MTY1LWJiMjAtNTJlNWE5MzFmMDdkLjhlZGFmZjQ5LTAwZTgtNGIzYi05ODExLTRjN2ZkZGM0NjJlMXgxNzkwODQzMjEwMTY2MjM1MDAw9832026/10/01 08:26:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjJjNDI4MDktNjNlMi00MTY1LWJiMjAtNTJlNWE5MzFmMDdkLjhlZGFmZjQ5LTAwZTgtNGIzYi05ODExLTRjN2ZkZGM0NjJlMXgxNzkwODQzMjEwMTY2MjM1MDAw parts=1984--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.30s)985=== CONT TestSkippedUploadsHandler9862026/10/01 08:26:50 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000987--- PASS: TestSkippedUploadsHandler (0.00s)988=== CONT TestParseSize989--- PASS: TestParseSize (0.00s)990=== CONT TestService_Rustfstest991--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.34s)992=== CONT TestPresignedUploadRegisteredBeforeCommit9932026-10-01 08:26:50.428 UTC [86411] ERROR: relation "goose_db_version" does not exist at character 369942026-10-01 08:26:50.428 UTC [86411] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9952026-10-01 08:26:50.525 UTC [86415] ERROR: relation "goose_db_version" does not exist at character 369962026-10-01 08:26:50.525 UTC [86415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9972026/10/01 08:26:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/01 08:26:50 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst999--- PASS: TestCompleteMultipartUnregistered (1.51s)1000=== CONT TestCompletedNarNotReofferedAcrossClosures10012026/10/01 08:26:50 OK 20241026095416_initial_model.sql (109.16ms)10022026/10/01 08:26:50 OK 20251210153512_drop_unused_gin_index.sql (5.44ms)10032026/10/01 08:26:50 OK 20251218171726_add_pins.sql (25.64ms)10042026/10/01 08:26:50 OK 20260628120000_add_object_size_and_stats.sql (15.48ms)10052026/10/01 08:26:50 OK 20260905000000_add_claims.sql (23.66ms)10062026/10/01 08:26:50 OK 20260920000000_drop_claims.sql (19.78ms)10072026/10/01 08:26:50 OK 20241026095416_initial_model.sql (87.65ms)10082026-10-01 08:26:50.673 UTC [86418] ERROR: relation "goose_db_version" does not exist at character 3610092026-10-01 08:26:50.673 UTC [86418] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10102026/10/01 08:26:50 OK 20251210153512_drop_unused_gin_index.sql (7.73ms)10112026/10/01 08:26:50 OK 20260923120000_add_pushes.sql (9.9ms)10122026/10/01 08:26:50 goose: successfully migrated database to version: 2026092312000010132026/10/01 08:26:50 OK 1_commit_pending_closure.sql (2.7ms)10142026/10/01 08:26:50 OK 2_object_stats_trigger.sql (583.83µs)10152026/10/01 08:26:50 OK 3_commit_push.sql (900.88µs)10162026/10/01 08:26:50 goose: up to current file version: 310172026/10/01 08:26:50 OK 20251218171726_add_pins.sql (7.24ms)10182026/10/01 08:26:50 OK 20260628120000_add_object_size_and_stats.sql (19.67ms)10192026/10/01 08:26:50 OK 20260905000000_add_claims.sql (33.91ms)10202026/10/01 08:26:50 OK 20260920000000_drop_claims.sql (22.1ms)1021--- PASS: TestReadProxyNarStreaming (1.72s)1022=== CONT TestReadProxyRangeRequest10232026/10/01 08:26:50 OK 20260923120000_add_pushes.sql (24.66ms)10242026/10/01 08:26:50 goose: successfully migrated database to version: 2026092312000010252026/10/01 08:26:50 OK 1_commit_pending_closure.sql (2.52ms)10262026/10/01 08:26:50 OK 2_object_stats_trigger.sql (529.88µs)10272026/10/01 08:26:50 OK 3_commit_push.sql (402.46µs)10282026/10/01 08:26:50 goose: up to current file version: 310292026/10/01 08:26:50 OK 20241026095416_initial_model.sql (106.83ms)10302026/10/01 08:26:50 OK 20251210153512_drop_unused_gin_index.sql (12.9ms)10312026/10/01 08:26:50 OK 20251218171726_add_pins.sql (23.5ms)10322026/10/01 08:26:50 OK 20260628120000_add_object_size_and_stats.sql (11.73ms)10332026/10/01 08:26:50 OK 20260905000000_add_claims.sql (22.54ms)10342026/10/01 08:26:50 OK 20260920000000_drop_claims.sql (17.84ms)10352026/10/01 08:26:50 OK 20260923120000_add_pushes.sql (17.97ms)10362026/10/01 08:26:50 goose: successfully migrated database to version: 2026092312000010372026/10/01 08:26:50 OK 1_commit_pending_closure.sql (4.1ms)10382026/10/01 08:26:50 OK 2_object_stats_trigger.sql (744.38µs)10392026/10/01 08:26:50 OK 3_commit_push.sql (494.13µs)10402026/10/01 08:26:50 goose: up to current file version: 310412026/10/01 08:26:50 INFO Received uploads request method=POST path=/api/pending_closures1042--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.96s)1043=== CONT TestRedundantMultipartUpload10442026-10-01 08:26:51.047 UTC [86421] ERROR: relation "goose_db_version" does not exist at character 3610452026-10-01 08:26:51.047 UTC [86421] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10462026/10/01 08:26:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10472026/10/01 08:26:51 WARN Refused reserved pin name=worker-x86_64-linux10482026/10/01 08:26:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10492026/10/01 08:26:51 INFO Received create pin request method=POST path=/api/pins/my-app10502026/10/01 08:26:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1051--- PASS: TestCreatePin_ReservedPins (2.09s)1052=== CONT TestPush_SignsNarinfosOfItsPendingObjects10532026/10/01 08:26:51 OK 20241026095416_initial_model.sql (91.42ms)10542026/10/01 08:26:51 OK 20251210153512_drop_unused_gin_index.sql (12.55ms)10552026/10/01 08:26:51 OK 20251218171726_add_pins.sql (4.63ms)10562026/10/01 08:26:51 OK 20260628120000_add_object_size_and_stats.sql (18.64ms)10572026/10/01 08:26:51 OK 20260905000000_add_claims.sql (21.87ms)10582026/10/01 08:26:51 OK 20260920000000_drop_claims.sql (15.19ms)10592026/10/01 08:26:51 OK 20260923120000_add_pushes.sql (5.09ms)10602026/10/01 08:26:51 goose: successfully migrated database to version: 2026092312000010612026/10/01 08:26:51 OK 1_commit_pending_closure.sql (2.8ms)10622026/10/01 08:26:51 OK 2_object_stats_trigger.sql (620.83µs)10632026/10/01 08:26:51 OK 3_commit_push.sql (386.92µs)10642026/10/01 08:26:51 goose: up to current file version: 310652026/10/01 08:26:51 INFO Received uploads request method=POST path=/api/pending_closures10662026-10-01 08:26:51.471 UTC [86427] ERROR: relation "goose_db_version" does not exist at character 3610672026-10-01 08:26:51.471 UTC [86427] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10682026-10-01 08:26:51.481 UTC [86428] ERROR: relation "goose_db_version" does not exist at character 3610692026-10-01 08:26:51.481 UTC [86428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10702026/10/01 08:26:51 INFO Received uploads request method=POST path=/api/pending_closures10712026/10/01 08:26:51 INFO Received uploads request method=POST path=/api/pending_closures10722026/10/01 08:26:51 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/01 08:26:51 OK 20241026095416_initial_model.sql (150.63ms)10742026/10/01 08:26:51 OK 20251210153512_drop_unused_gin_index.sql (18.74ms)10752026/10/01 08:26:51 OK 20241026095416_initial_model.sql (164.61ms)10762026/10/01 08:26:51 OK 20251210153512_drop_unused_gin_index.sql (7.81ms)10772026/10/01 08:26:51 OK 20251218171726_add_pins.sql (17.54ms)10782026/10/01 08:26:51 OK 20251218171726_add_pins.sql (21.88ms)10792026/10/01 08:26:51 OK 20260628120000_add_object_size_and_stats.sql (45.22ms)10802026/10/01 08:26:51 OK 20260628120000_add_object_size_and_stats.sql (55.12ms)10812026/10/01 08:26:51 OK 20260905000000_add_claims.sql (62.81ms)10822026/10/01 08:26:51 OK 20260905000000_add_claims.sql (61.97ms)10832026/10/01 08:26:51 OK 20260920000000_drop_claims.sql (30.84ms)10842026/10/01 08:26:51 OK 20260923120000_add_pushes.sql (13.56ms)10852026/10/01 08:26:51 goose: successfully migrated database to version: 2026092312000010862026/10/01 08:26:51 OK 20260920000000_drop_claims.sql (22.65ms)10872026/10/01 08:26:51 OK 1_commit_pending_closure.sql (2.84ms)10882026/10/01 08:26:51 OK 2_object_stats_trigger.sql (425.29µs)10892026/10/01 08:26:51 OK 3_commit_push.sql (352.88µs)10902026/10/01 08:26:51 goose: up to current file version: 310912026/10/01 08:26:51 OK 20260923120000_add_pushes.sql (19.58ms)10922026/10/01 08:26:51 goose: successfully migrated database to version: 2026092312000010932026/10/01 08:26:51 OK 1_commit_pending_closure.sql (1.6ms)10942026/10/01 08:26:51 OK 2_object_stats_trigger.sql (346.63µs)10952026/10/01 08:26:51 OK 3_commit_push.sql (288.96µs)10962026/10/01 08:26:51 goose: up to current file version: 310972026/10/01 08:26:51 INFO Received cleanup request method=DELETE path=/api/pending_closures10982026/10/01 08:26:51 INFO Aborted multipart uploads count=010992026/10/01 08:26:51 INFO Received uploads request method=POST path=/api/pending_closures11002026/10/01 08:26:51 INFO Received cleanup request method=DELETE path=/api/pending_closures11012026/10/01 08:26:51 INFO Aborted multipart uploads count=111022026/10/01 08:26:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11032026-10-01 08:26:51.999 UTC [86418] ERROR: Closure does not exist: id=111042026-10-01 08:26:51.999 UTC [86418] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11052026-10-01 08:26:51.999 UTC [86418] STATEMENT: -- name: CommitPendingClosure :exec1106 SELECT commit_pending_closure($1::bigint)1107 1108--- PASS: TestService_cleanupPendingClosuresHandler (2.18s)1109=== CONT TestPush_RejectsBadRequests11102026-10-01 08:26:52.144 UTC [86431] ERROR: relation "goose_db_version" does not exist at character 3611112026-10-01 08:26:52.144 UTC [86431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11122026/10/01 08:26:52 INFO Received uploads request method=POST path=/api/pending_closures11132026-10-01 08:26:52.326 UTC [86432] ERROR: relation "goose_db_version" does not exist at character 3611142026-10-01 08:26:52.326 UTC [86432] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11152026/10/01 08:26:52 OK 20241026095416_initial_model.sql (150.69ms)11162026/10/01 08:26:52 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)11172026/10/01 08:26:52 OK 20251218171726_add_pins.sql (45.68ms)11182026/10/01 08:26:52 OK 20260628120000_add_object_size_and_stats.sql (45.71ms)11192026/10/01 08:26:52 OK 20260905000000_add_claims.sql (47.12ms)11202026/10/01 08:26:52 OK 20260920000000_drop_claims.sql (15.93ms)11212026/10/01 08:26:52 OK 20260923120000_add_pushes.sql (19.05ms)11222026/10/01 08:26:52 goose: successfully migrated database to version: 2026092312000011232026/10/01 08:26:52 OK 20241026095416_initial_model.sql (148.4ms)11242026/10/01 08:26:52 OK 1_commit_pending_closure.sql (2.19ms)11252026/10/01 08:26:52 OK 2_object_stats_trigger.sql (480.38µs)11262026/10/01 08:26:52 OK 3_commit_push.sql (319.75µs)11272026/10/01 08:26:52 goose: up to current file version: 311282026/10/01 08:26:52 OK 20251210153512_drop_unused_gin_index.sql (29.31ms)11292026/10/01 08:26:52 OK 20251218171726_add_pins.sql (37.87ms)11302026/10/01 08:26:52 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/01 08:26:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11322026-10-01 08:26:52.644 UTC [86433] ERROR: relation "goose_db_version" does not exist at character 3611332026-10-01 08:26:52.644 UTC [86433] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/10/01 08:26:52 OK 20260628120000_add_object_size_and_stats.sql (55.15ms)11352026/10/01 08:26:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11362026/10/01 08:26:52 INFO Received uploads request method=POST path=/api/pending_closures11372026/10/01 08:26:52 OK 20260905000000_add_claims.sql (25.36ms)1138--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.28s)1139=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11402026/10/01 08:26:52 OK 20260920000000_drop_claims.sql (67.27ms)11412026/10/01 08:26:52 OK 20260923120000_add_pushes.sql (25.63ms)11422026/10/01 08:26:52 goose: successfully migrated database to version: 2026092312000011432026/10/01 08:26:52 OK 1_commit_pending_closure.sql (2.69ms)11442026/10/01 08:26:52 OK 2_object_stats_trigger.sql (520.42µs)11452026/10/01 08:26:52 OK 3_commit_push.sql (325.08µs)11462026/10/01 08:26:52 goose: up to current file version: 311472026/10/01 08:26:52 OK 20241026095416_initial_model.sql (194.67ms)1148--- PASS: TestService_Rustfstest (2.52s)1149=== CONT TestPush_CompleteCommitsEveryRoot11502026/10/01 08:26:52 OK 20251210153512_drop_unused_gin_index.sql (13.62ms)11512026/10/01 08:26:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11522026/10/01 08:26:52 OK 20251218171726_add_pins.sql (39.93ms)11532026-10-01 08:26:52.979 UTC [86438] ERROR: relation "goose_db_version" does not exist at character 3611542026-10-01 08:26:52.979 UTC [86438] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11552026/10/01 08:26:52 OK 20260628120000_add_object_size_and_stats.sql (44.14ms)11562026/10/01 08:26:52 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjJjNDI4MDktNjNlMi00MTY1LWJiMjAtNTJlNWE5MzFmMDdkLmUxZmM0NjlkLWM0M2EtNGRjYS1hYzczLTU3YWYzNDNkYjNmY3gxNzkwODQzMjExMzk4MzA5MDAw parts=1011572026/10/01 08:26:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11582026/10/01 08:26:53 INFO Completed upload id=111592026/10/01 08:26:53 INFO Received uploads request method=POST path=/api/pending_closures11602026/10/01 08:26:53 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/01 08:26:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11622026/10/01 08:26:53 WARN Found objects in DB but missing from S3, will re-upload count=11163--- PASS: TestService_verifyS3Integrity (3.46s)1164=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11652026/10/01 08:26:53 OK 20260905000000_add_claims.sql (57.26ms)11662026/10/01 08:26:53 OK 20260920000000_drop_claims.sql (20.69ms)11672026/10/01 08:26:53 OK 20260923120000_add_pushes.sql (17.06ms)11682026/10/01 08:26:53 goose: successfully migrated database to version: 2026092312000011692026/10/01 08:26:53 OK 1_commit_pending_closure.sql (1.72ms)11702026/10/01 08:26:53 OK 2_object_stats_trigger.sql (443.21µs)11712026/10/01 08:26:53 OK 3_commit_push.sql (248.21µs)11722026/10/01 08:26:53 goose: up to current file version: 311732026/10/01 08:26:53 INFO Received uploads request method=POST path=/api/pending_closures11742026/10/01 08:26:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11752026/10/01 08:26:53 OK 20241026095416_initial_model.sql (140.75ms)11762026/10/01 08:26:53 OK 20251210153512_drop_unused_gin_index.sql (19.95ms)11772026/10/01 08:26:53 OK 20251218171726_add_pins.sql (26.11ms)11782026/10/01 08:26:53 OK 20260628120000_add_object_size_and_stats.sql (14.54ms)11792026/10/01 08:26:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjJjNDI4MDktNjNlMi00MTY1LWJiMjAtNTJlNWE5MzFmMDdkLmYxNDJjMmMxLTBkZmUtNDc4MS1hNzMzLTUwZjdkNTI2MjJmZXgxNzkwODQzMjExNjEzMzI0MDAw parts=1011802026/10/01 08:26:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11812026/10/01 08:26:53 INFO Completed upload id=111822026/10/01 08:26:53 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011832026/10/01 08:26:53 INFO Received uploads request method=POST path=/api/pending_closures11842026/10/01 08:26:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures11852026/10/01 08:26:53 INFO Aborted multipart uploads count=011862026/10/01 08:26:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011872026/10/01 08:26:53 INFO Vacuumed table table=pending_closures11882026/10/01 08:26:53 OK 20260905000000_add_claims.sql (59.56ms)11892026/10/01 08:26:53 INFO Vacuumed table table=pending_objects11902026/10/01 08:26:53 OK 20260920000000_drop_claims.sql (25.25ms)11912026/10/01 08:26:53 OK 20260923120000_add_pushes.sql (5.36ms)11922026/10/01 08:26:53 goose: successfully migrated database to version: 2026092312000011932026/10/01 08:26:53 INFO Vacuumed table table=multipart_uploads11942026/10/01 08:26:53 OK 1_commit_pending_closure.sql (3.06ms)11952026/10/01 08:26:53 OK 2_object_stats_trigger.sql (586.13µs)11962026/10/01 08:26:53 OK 3_commit_push.sql (349.67µs)11972026/10/01 08:26:53 goose: up to current file version: 311982026/10/01 08:26:53 INFO Vacuumed table table=closures11992026/10/01 08:26:53 INFO Vacuumed table table=objects12002026/10/01 08:26:53 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001201--- PASS: TestService_createPendingClosureHandler (3.76s)1202=== CONT TestReadRedirectUsesPublicS3URL1203--- PASS: TestReadProxyRangeRequest (2.67s)1204=== CONT TestFailedS3DeleteKeepsTombstone12052026/10/01 08:26:53 INFO Received uploads request method=POST path=/api/pending_closures12062026/10/01 08:26:53 INFO Received uploads request method=POST path=/api/pending_closures12072026-10-01 08:26:53.786 UTC [86447] ERROR: relation "goose_db_version" does not exist at character 3612082026-10-01 08:26:53.786 UTC [86447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12092026/10/01 08:26:53 INFO Received push request method=POST path=/api/pushes12102026/10/01 08:26:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12112026/10/01 08:26:54 OK 20241026095416_initial_model.sql (150.92ms)12122026/10/01 08:26:54 INFO Signed narinfos id=1 count=11213--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.86s)1214=== CONT TestOrphanedObjectsGCStressTest12152026/10/01 08:26:54 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)12162026/10/01 08:26:54 OK 20251218171726_add_pins.sql (27.14ms)12172026/10/01 08:26:54 OK 20260628120000_add_object_size_and_stats.sql (39.25ms)12182026/10/01 08:26:54 OK 20260905000000_add_claims.sql (24.18ms)12192026/10/01 08:26:54 OK 20260920000000_drop_claims.sql (47.36ms)12202026/10/01 08:26:54 OK 20260923120000_add_pushes.sql (13.25ms)12212026/10/01 08:26:54 goose: successfully migrated database to version: 2026092312000012222026/10/01 08:26:54 OK 1_commit_pending_closure.sql (2.15ms)12232026/10/01 08:26:54 OK 2_object_stats_trigger.sql (412.63µs)12242026/10/01 08:26:54 OK 3_commit_push.sql (359.75µs)12252026/10/01 08:26:54 goose: up to current file version: 312262026-10-01 08:26:54.360 UTC [86450] ERROR: relation "goose_db_version" does not exist at character 3612272026-10-01 08:26:54.360 UTC [86450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1228=== RUN TestPush_RejectsBadRequests/root_not_in_objects1229=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1230=== RUN TestPush_RejectsBadRequests/no_roots1231=== PAUSE TestPush_RejectsBadRequests/no_roots1232=== RUN TestPush_RejectsBadRequests/no_objects1233=== PAUSE TestPush_RejectsBadRequests/no_objects1234=== RUN TestPush_RejectsBadRequests/bad_root1235=== PAUSE TestPush_RejectsBadRequests/bad_root1236=== CONT TestOrphanedObjectsGC12372026/10/01 08:26:54 OK 20241026095416_initial_model.sql (122.62ms)12382026/10/01 08:26:54 OK 20251210153512_drop_unused_gin_index.sql (14.12ms)12392026/10/01 08:26:54 OK 20251218171726_add_pins.sql (21.96ms)12402026/10/01 08:26:54 OK 20260628120000_add_object_size_and_stats.sql (9.7ms)12412026-10-01 08:26:54.594 UTC [86453] ERROR: relation "goose_db_version" does not exist at character 3612422026-10-01 08:26:54.594 UTC [86453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12432026-10-01 08:26:54.595 UTC [86454] ERROR: relation "goose_db_version" does not exist at character 3612442026-10-01 08:26:54.595 UTC [86454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12452026/10/01 08:26:54 OK 20260905000000_add_claims.sql (7.38ms)12462026/10/01 08:26:54 OK 20260920000000_drop_claims.sql (2.01ms)12472026/10/01 08:26:54 OK 20260923120000_add_pushes.sql (2.96ms)12482026/10/01 08:26:54 goose: successfully migrated database to version: 2026092312000012492026/10/01 08:26:54 OK 1_commit_pending_closure.sql (1.95ms)12502026/10/01 08:26:54 OK 2_object_stats_trigger.sql (436.92µs)12512026/10/01 08:26:54 OK 3_commit_push.sql (318.25µs)12522026/10/01 08:26:54 goose: up to current file version: 312532026/10/01 08:26:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12542026/10/01 08:26:54 OK 20241026095416_initial_model.sql (127.32ms)12552026/10/01 08:26:54 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjJjNDI4MDktNjNlMi00MTY1LWJiMjAtNTJlNWE5MzFmMDdkLjZhZTY2YmZiLTA3ZjMtNDlkNy1hYmE1LWJiZWNhMzQ1ZjI2YngxNzkwODQzMjEzMTc1MzgxMDAw parts=1212562026/10/01 08:26:54 INFO Received uploads request method=POST path=/api/pending_closures1257--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.19s)1258=== CONT TestReadProxyRootRedirectsToIndexHTML12592026/10/01 08:26:54 OK 20251210153512_drop_unused_gin_index.sql (27ms)12602026/10/01 08:26:54 OK 20241026095416_initial_model.sql (174.62ms)12612026/10/01 08:26:54 OK 20251210153512_drop_unused_gin_index.sql (13.79ms)12622026/10/01 08:26:54 OK 20251218171726_add_pins.sql (41.54ms)12632026/10/01 08:26:54 OK 20251218171726_add_pins.sql (26.9ms)12642026/10/01 08:26:54 OK 20260628120000_add_object_size_and_stats.sql (25.27ms)12652026/10/01 08:26:54 OK 20260628120000_add_object_size_and_stats.sql (22.82ms)12662026/10/01 08:26:54 INFO Received push request method=POST path=/api/pushes12672026/10/01 08:26:54 OK 20260905000000_add_claims.sql (48.95ms)12682026/10/01 08:26:54 OK 20260905000000_add_claims.sql (50.28ms)12692026/10/01 08:26:54 OK 20260920000000_drop_claims.sql (44.47ms)12702026/10/01 08:26:54 OK 20260920000000_drop_claims.sql (48.9ms)12712026/10/01 08:26:54 OK 20260923120000_add_pushes.sql (38.38ms)12722026/10/01 08:26:54 goose: successfully migrated database to version: 2026092312000012732026/10/01 08:26:54 OK 1_commit_pending_closure.sql (2.76ms)12742026/10/01 08:26:54 OK 2_object_stats_trigger.sql (587.21µs)12752026/10/01 08:26:54 OK 3_commit_push.sql (343.5µs)12762026/10/01 08:26:54 goose: up to current file version: 312772026/10/01 08:26:54 OK 20260923120000_add_pushes.sql (22.24ms)12782026/10/01 08:26:54 goose: successfully migrated database to version: 2026092312000012792026/10/01 08:26:55 OK 1_commit_pending_closure.sql (2.48ms)12802026/10/01 08:26:55 OK 2_object_stats_trigger.sql (512.75µs)12812026/10/01 08:26:55 OK 3_commit_push.sql (395.46µs)12822026/10/01 08:26:55 goose: up to current file version: 312832026/10/01 08:26:55 INFO Received complete push request method=POST path=/api/pushes/1/complete12842026/10/01 08:26:55 INFO Received push request method=POST path=/api/pushes12852026/10/01 08:26:55 INFO Aborted multipart uploads count=012862026/10/01 08:26:55 WARN Force mode enabled - objects will be deleted immediately without grace period12872026/10/01 08:26:55 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=012882026/10/01 08:26:55 INFO Vacuumed table table=pending_closures12892026/10/01 08:26:55 INFO Vacuumed table table=pending_objects12902026/10/01 08:26:55 INFO Vacuumed table table=multipart_uploads12912026/10/01 08:26:55 INFO Vacuumed table table=closures12922026/10/01 08:26:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12932026/10/01 08:26:55 INFO Received push request method=POST path=/api/pushes12942026/10/01 08:26:55 INFO Vacuumed table table=objects12952026/10/01 08:26:55 INFO Received complete push request method=POST path=/api/pushes/2/complete1296--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.69s)1297=== CONT TestObjectStatsTrigger12982026/10/01 08:26:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjJjNDI4MDktNjNlMi00MTY1LWJiMjAtNTJlNWE5MzFmMDdkLjM1NTMyYzQ1LWJkZTUtNDU4Yy1iOThkLTlkYWY1YmI5OTE2NXgxNzkwODQzMjEzNjg0OTQwMDAw parts=121299--- PASS: TestRedundantMultipartUpload (4.42s)1300=== CONT TestMultipartCleanup1301--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.46s)1302=== CONT TestServerTLSConfig1303=== RUN TestServerTLSConfig/no_client_CA1304=== PAUSE TestServerTLSConfig/no_client_CA1305=== RUN TestServerTLSConfig/missing_CA_file1306=== PAUSE TestServerTLSConfig/missing_CA_file1307=== RUN TestServerTLSConfig/not_a_PEM_file1308=== PAUSE TestServerTLSConfig/not_a_PEM_file1309=== CONT TestReadRedirectKeepsNarinfoProxied13102026/10/01 08:26:55 INFO Received push request method=POST path=/api/pushes13112026/10/01 08:26:55 INFO Received complete push request method=POST path=/api/pushes/1/complete13122026-10-01 08:26:55.898 UTC [86466] ERROR: relation "goose_db_version" does not exist at character 3613132026-10-01 08:26:55.898 UTC [86466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13142026-10-01 08:26:55.917 UTC [86467] ERROR: relation "goose_db_version" does not exist at character 3613152026-10-01 08:26:55.917 UTC [86467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1316--- PASS: TestPush_CompleteCommitsEveryRoot (3.03s)1317=== CONT TestService_NativeMTLS13182026/10/01 08:26:56 OK 20241026095416_initial_model.sql (91.8ms)13192026/10/01 08:26:56 OK 20241026095416_initial_model.sql (77.23ms)13202026/10/01 08:26:56 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)13212026/10/01 08:26:56 OK 20251210153512_drop_unused_gin_index.sql (6.32ms)13222026/10/01 08:26:56 OK 20251218171726_add_pins.sql (20.29ms)13232026/10/01 08:26:56 OK 20251218171726_add_pins.sql (29.55ms)13242026-10-01 08:26:56.078 UTC [86472] ERROR: relation "goose_db_version" does not exist at character 3613252026-10-01 08:26:56.078 UTC [86472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13262026/10/01 08:26:56 OK 20260628120000_add_object_size_and_stats.sql (23.88ms)13272026/10/01 08:26:56 OK 20260628120000_add_object_size_and_stats.sql (18.91ms)13282026/10/01 08:26:56 OK 20260905000000_add_claims.sql (38.19ms)13292026/10/01 08:26:56 OK 20260905000000_add_claims.sql (29.08ms)13302026/10/01 08:26:56 OK 20260920000000_drop_claims.sql (6.27ms)13312026/10/01 08:26:56 OK 20260920000000_drop_claims.sql (5.36ms)13322026/10/01 08:26:56 OK 20260923120000_add_pushes.sql (11.01ms)13332026/10/01 08:26:56 goose: successfully migrated database to version: 2026092312000013342026/10/01 08:26:56 OK 20260923120000_add_pushes.sql (11.4ms)13352026/10/01 08:26:56 goose: successfully migrated database to version: 2026092312000013362026/10/01 08:26:56 OK 1_commit_pending_closure.sql (2.92ms)13372026/10/01 08:26:56 OK 1_commit_pending_closure.sql (2.35ms)13382026/10/01 08:26:56 OK 2_object_stats_trigger.sql (555.46µs)13392026/10/01 08:26:56 OK 2_object_stats_trigger.sql (627µs)13402026/10/01 08:26:56 OK 3_commit_push.sql (342.75µs)13412026/10/01 08:26:56 goose: up to current file version: 313422026/10/01 08:26:56 OK 3_commit_push.sql (434.88µs)13432026/10/01 08:26:56 goose: up to current file version: 313442026/10/01 08:26:56 OK 20241026095416_initial_model.sql (163.06ms)13452026/10/01 08:26:56 OK 20251210153512_drop_unused_gin_index.sql (9.79ms)13462026/10/01 08:26:56 OK 20251218171726_add_pins.sql (37.95ms)13472026/10/01 08:26:56 OK 20260628120000_add_object_size_and_stats.sql (43.07ms)13482026/10/01 08:26:56 INFO Received uploads request method=POST path=/api/pending_closures13492026/10/01 08:26:56 OK 20260905000000_add_claims.sql (85.75ms)13502026/10/01 08:26:56 WARN Rate limiter enabled after throttle name=s3-test rate=513512026/10/01 08:26:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1352=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1353 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101354 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001355--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.42s)1356=== CONT TestReadRedirectNar13572026/10/01 08:26:56 OK 20260920000000_drop_claims.sql (37.02ms)13582026-10-01 08:26:56.496 UTC [86473] ERROR: relation "goose_db_version" does not exist at character 3613592026-10-01 08:26:56.496 UTC [86473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13602026/10/01 08:26:56 OK 20260923120000_add_pushes.sql (107.81ms)13612026/10/01 08:26:56 goose: successfully migrated database to version: 2026092312000013622026/10/01 08:26:56 OK 1_commit_pending_closure.sql (4.17ms)13632026/10/01 08:26:56 OK 2_object_stats_trigger.sql (952.75µs)13642026/10/01 08:26:56 OK 3_commit_push.sql (592.25µs)13652026/10/01 08:26:56 goose: up to current file version: 313662026/10/01 08:26:56 INFO Aborted multipart uploads count=013672026/10/01 08:26:56 WARN Force mode enabled - objects will be deleted immediately without grace period13682026/10/01 08:26:56 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13692026/10/01 08:26:56 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1370--- PASS: TestFailedS3DeleteKeepsTombstone (3.24s)1371=== CONT TestMetricsInventory1372--- PASS: TestReadRedirectUsesPublicS3URL (3.35s)1373=== CONT TestNARDeduplicationMetadataUploadBug13742026/10/01 08:26:56 OK 20241026095416_initial_model.sql (208.17ms)13752026/10/01 08:26:56 OK 20251210153512_drop_unused_gin_index.sql (18.13ms)13762026/10/01 08:26:56 OK 20251218171726_add_pins.sql (17.48ms)13772026/10/01 08:26:56 OK 20260628120000_add_object_size_and_stats.sql (29.57ms)13782026/10/01 08:26:56 OK 20260905000000_add_claims.sql (101.17ms)13792026/10/01 08:26:57 OK 20260920000000_drop_claims.sql (59.33ms)13802026/10/01 08:26:57 OK 20260923120000_add_pushes.sql (23.15ms)13812026/10/01 08:26:57 goose: successfully migrated database to version: 2026092312000013822026/10/01 08:26:57 OK 1_commit_pending_closure.sql (4.41ms)13832026/10/01 08:26:57 OK 2_object_stats_trigger.sql (766.17µs)13842026/10/01 08:26:57 OK 3_commit_push.sql (510.79µs)13852026/10/01 08:26:57 goose: up to current file version: 313862026-10-01 08:26:57.387 UTC [86481] ERROR: relation "goose_db_version" does not exist at character 3613872026-10-01 08:26:57.387 UTC [86481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13882026/10/01 08:26:57 OK 20241026095416_initial_model.sql (285.4ms)13892026/10/01 08:26:57 OK 20251210153512_drop_unused_gin_index.sql (17.24ms)13902026/10/01 08:26:57 OK 20251218171726_add_pins.sql (15.85ms)13912026/10/01 08:26:57 OK 20260628120000_add_object_size_and_stats.sql (35.6ms)13922026-10-01 08:26:57.865 UTC [86483] ERROR: relation "goose_db_version" does not exist at character 3613932026-10-01 08:26:57.865 UTC [86483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13942026-10-01 08:26:57.889 UTC [86482] ERROR: relation "goose_db_version" does not exist at character 3613952026-10-01 08:26:57.889 UTC [86482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13962026/10/01 08:26:57 OK 20260905000000_add_claims.sql (95.35ms)13972026/10/01 08:26:57 OK 20260920000000_drop_claims.sql (55.48ms)13982026/10/01 08:26:58 OK 20260923120000_add_pushes.sql (9.63ms)13992026/10/01 08:26:58 goose: successfully migrated database to version: 2026092312000014002026-10-01 08:26:58.006 UTC [86484] ERROR: relation "goose_db_version" does not exist at character 3614012026-10-01 08:26:58.006 UTC [86484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14022026/10/01 08:26:58 OK 1_commit_pending_closure.sql (3.1ms)14032026/10/01 08:26:58 OK 2_object_stats_trigger.sql (602.58µs)14042026/10/01 08:26:58 OK 3_commit_push.sql (377.21µs)14052026/10/01 08:26:58 goose: up to current file version: 314062026/10/01 08:26:58 OK 20241026095416_initial_model.sql (323.04ms)14072026/10/01 08:26:58 OK 20241026095416_initial_model.sql (299.56ms)14082026/10/01 08:26:58 OK 20251210153512_drop_unused_gin_index.sql (26.55ms)14092026/10/01 08:26:58 OK 20251210153512_drop_unused_gin_index.sql (26.72ms)14102026/10/01 08:26:58 OK 20251218171726_add_pins.sql (50.89ms)14112026/10/01 08:26:58 OK 20241026095416_initial_model.sql (299.79ms)14122026/10/01 08:26:58 OK 20251218171726_add_pins.sql (64.59ms)14132026/10/01 08:26:58 OK 20251210153512_drop_unused_gin_index.sql (13.23ms)14142026/10/01 08:26:58 OK 20260628120000_add_object_size_and_stats.sql (68.73ms)14152026/10/01 08:26:58 OK 20251218171726_add_pins.sql (52.52ms)14162026/10/01 08:26:58 OK 20260628120000_add_object_size_and_stats.sql (76.8ms)1417--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.71s)1418=== CONT TestReadProxyDisabled14192026/10/01 08:26:58 OK 20260905000000_add_claims.sql (44.32ms)14202026/10/01 08:26:58 OK 20260628120000_add_object_size_and_stats.sql (43.15ms)14212026/10/01 08:26:58 OK 20260905000000_add_claims.sql (41ms)14222026/10/01 08:26:58 OK 20260920000000_drop_claims.sql (32.76ms)14232026/10/01 08:26:58 OK 20260920000000_drop_claims.sql (17.21ms)14242026/10/01 08:26:58 OK 20260923120000_add_pushes.sql (3.85ms)14252026/10/01 08:26:58 goose: successfully migrated database to version: 2026092312000014262026/10/01 08:26:58 OK 20260905000000_add_claims.sql (30.06ms)14272026/10/01 08:26:58 OK 1_commit_pending_closure.sql (2.01ms)14282026/10/01 08:26:58 OK 2_object_stats_trigger.sql (413.67µs)14292026/10/01 08:26:58 OK 3_commit_push.sql (826.04µs)14302026/10/01 08:26:58 goose: up to current file version: 314312026/10/01 08:26:58 OK 20260923120000_add_pushes.sql (5.12ms)14322026/10/01 08:26:58 goose: successfully migrated database to version: 2026092312000014332026/10/01 08:26:58 OK 1_commit_pending_closure.sql (1.54ms)14342026/10/01 08:26:58 OK 2_object_stats_trigger.sql (361.88µs)14352026/10/01 08:26:58 OK 3_commit_push.sql (313.5µs)14362026/10/01 08:26:58 goose: up to current file version: 31437=== NAME TestOrphanedObjectsGC1438 orphaned_objects_gc_test.go:290: GC Test Summary:1439 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1440 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1441 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1442 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1443 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1444--- PASS: TestOrphanedObjectsGC (4.15s)1445=== CONT TestCreatePendingClosureRejectsOversizedNAR14462026/10/01 08:26:58 INFO Received uploads request method=POST path=/api/pending_closures1447--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1448=== CONT TestCacheConfigHandlerMaxNarSize1449--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1450=== CONT TestGenerateLandingPage1451--- PASS: TestGenerateLandingPage (0.00s)1452=== CONT TestService_readinessHandler14532026/10/01 08:26:58 OK 20260920000000_drop_claims.sql (48.77ms)14542026/10/01 08:26:58 OK 20260923120000_add_pushes.sql (11.55ms)14552026/10/01 08:26:58 goose: successfully migrated database to version: 2026092312000014562026/10/01 08:26:58 OK 1_commit_pending_closure.sql (1.75ms)14572026/10/01 08:26:58 OK 2_object_stats_trigger.sql (398µs)14582026/10/01 08:26:58 OK 3_commit_push.sql (266.42µs)14592026/10/01 08:26:58 goose: up to current file version: 314602026-10-01 08:26:58.603 UTC [86487] ERROR: relation "goose_db_version" does not exist at character 3614612026-10-01 08:26:58.603 UTC [86487] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1462--- PASS: TestObjectStatsTrigger (3.54s)1463=== CONT TestService_healthCheckHandler14642026/10/01 08:26:58 OK 20241026095416_initial_model.sql (241.99ms)14652026/10/01 08:26:58 OK 20251210153512_drop_unused_gin_index.sql (8.91ms)14662026/10/01 08:26:58 OK 20251218171726_add_pins.sql (35.45ms)14672026/10/01 08:26:59 OK 20260628120000_add_object_size_and_stats.sql (41.31ms)14682026/10/01 08:26:59 OK 20260905000000_add_claims.sql (68.08ms)14692026/10/01 08:26:59 OK 20260920000000_drop_claims.sql (75.97ms)14702026/10/01 08:26:59 OK 20260923120000_add_pushes.sql (40.55ms)14712026/10/01 08:26:59 goose: successfully migrated database to version: 2026092312000014722026/10/01 08:26:59 OK 1_commit_pending_closure.sql (6.32ms)14732026/10/01 08:26:59 OK 2_object_stats_trigger.sql (4.03ms)14742026/10/01 08:26:59 OK 3_commit_push.sql (1.62ms)14752026/10/01 08:26:59 goose: up to current file version: 31476--- PASS: TestReadRedirectKeepsNarinfoProxied (3.75s)1477=== CONT TestGracefulShutdownDrainsInflight14782026/10/01 08:26:59 INFO Starting HTTP server address=127.0.0.1:6000814792026/10/01 08:26:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1480--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1481=== CONT TestGCTaskStore_Fail1482--- PASS: TestGCTaskStore_Fail (0.00s)1483=== CONT TestGCTaskStore_PhaseUpdates1484--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1485=== CONT TestGCTaskStore_CompletedAllowsNewTask1486--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1487=== CONT TestGCTaskStore_GetReturnsLatest1488--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1489=== CONT TestPinProtectsFromGC14902026-10-01 08:26:59.347 UTC [86493] ERROR: relation "goose_db_version" does not exist at character 3614912026-10-01 08:26:59.347 UTC [86493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14922026-10-01 08:26:59.403 UTC [86495] ERROR: relation "goose_db_version" does not exist at character 3614932026-10-01 08:26:59.403 UTC [86495] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14942026/10/01 08:26:59 INFO Received uploads request method=POST path=/api/pending_closures14952026-10-01 08:26:59.585 UTC [86496] ERROR: relation "goose_db_version" does not exist at character 3614962026-10-01 08:26:59.585 UTC [86496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14972026/10/01 08:26:59 OK 20241026095416_initial_model.sql (190.67ms)14982026/10/01 08:26:59 OK 20251210153512_drop_unused_gin_index.sql (20.35ms)14992026/10/01 08:26:59 OK 20251218171726_add_pins.sql (23.65ms)15002026/10/01 08:26:59 OK 20241026095416_initial_model.sql (196.94ms)15012026/10/01 08:26:59 OK 20260628120000_add_object_size_and_stats.sql (25.83ms)15022026/10/01 08:26:59 OK 20251210153512_drop_unused_gin_index.sql (11.51ms)15032026/10/01 08:26:59 INFO Received cleanup request method=DELETE path=/api/pending_closures15042026/10/01 08:26:59 INFO Aborted multipart uploads count=115052026/10/01 08:26:59 OK 20251218171726_add_pins.sql (29.53ms)1506--- PASS: TestMultipartCleanup (4.27s)1507=== CONT TestGCTaskStore_GetEmpty1508--- PASS: TestGCTaskStore_GetEmpty (0.00s)1509=== CONT TestForceGCDuringPushOffersSweptObject1510=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1511=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1512=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1513=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1514=== CONT TestGCTaskStore_ConflictDifferentParams1515--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1516=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15172026/10/01 08:26:59 OK 20260905000000_add_claims.sql (52.41ms)15182026/10/01 08:26:59 OK 20260628120000_add_object_size_and_stats.sql (21.34ms)15192026/10/01 08:26:59 OK 20260920000000_drop_claims.sql (36.43ms)15202026/10/01 08:26:59 OK 20260923120000_add_pushes.sql (22.12ms)15212026/10/01 08:26:59 goose: successfully migrated database to version: 2026092312000015222026/10/01 08:26:59 OK 1_commit_pending_closure.sql (2.79ms)15232026/10/01 08:26:59 OK 2_object_stats_trigger.sql (539.33µs)15242026/10/01 08:26:59 OK 3_commit_push.sql (382.08µs)15252026/10/01 08:26:59 goose: up to current file version: 315262026/10/01 08:26:59 OK 20260905000000_add_claims.sql (69.93ms)15272026/10/01 08:26:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15282026/10/01 08:26:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1529--- PASS: TestService_NativeMTLS (3.88s)1530=== CONT TestGCTaskStore_DeduplicateSameParams1531--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1532=== CONT TestCacheStatsHandler15332026/10/01 08:26:59 OK 20260920000000_drop_claims.sql (46.86ms)15342026/10/01 08:26:59 OK 20241026095416_initial_model.sql (190.59ms)15352026/10/01 08:26:59 OK 20251210153512_drop_unused_gin_index.sql (14.05ms)15362026/10/01 08:26:59 OK 20260923120000_add_pushes.sql (16.95ms)15372026/10/01 08:26:59 goose: successfully migrated database to version: 2026092312000015382026/10/01 08:26:59 OK 1_commit_pending_closure.sql (2.66ms)15392026/10/01 08:26:59 OK 2_object_stats_trigger.sql (460.46µs)15402026/10/01 08:26:59 OK 3_commit_push.sql (355.13µs)15412026/10/01 08:26:59 goose: up to current file version: 315422026/10/01 08:26:59 OK 20251218171726_add_pins.sql (74.51ms)15432026/10/01 08:26:59 OK 20260628120000_add_object_size_and_stats.sql (30ms)15442026/10/01 08:27:00 OK 20260905000000_add_claims.sql (40.23ms)15452026/10/01 08:27:00 OK 20260920000000_drop_claims.sql (37.41ms)15462026/10/01 08:27:00 OK 20260923120000_add_pushes.sql (17.38ms)15472026/10/01 08:27:00 goose: successfully migrated database to version: 2026092312000015482026/10/01 08:27:00 OK 1_commit_pending_closure.sql (4.35ms)15492026/10/01 08:27:00 OK 2_object_stats_trigger.sql (807.5µs)15502026/10/01 08:27:00 OK 3_commit_push.sql (858.63µs)15512026/10/01 08:27:00 goose: up to current file version: 31552--- PASS: TestReadRedirectNar (3.61s)1553=== CONT TestGCSweepDeliversEachKeyOnce1554--- PASS: TestMetricsInventory (3.75s)1555=== CONT TestGCTaskStore_StartNew1556--- PASS: TestGCTaskStore_StartNew (0.00s)1557=== CONT TestTombstonedObjectOfferedWithoutWaiting15582026-10-01 08:27:00.742 UTC [86508] ERROR: relation "goose_db_version" does not exist at character 3615592026-10-01 08:27:00.742 UTC [86508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15602026-10-01 08:27:00.778 UTC [86510] ERROR: relation "goose_db_version" does not exist at character 3615612026-10-01 08:27:00.778 UTC [86510] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15622026-10-01 08:27:00.834 UTC [86512] ERROR: relation "goose_db_version" does not exist at character 3615632026-10-01 08:27:00.834 UTC [86512] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1564=== NAME TestNARDeduplicationMetadataUploadBug1565 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-86274-2014532869/TestNARDeduplicationMetadataUploadBug474214115/001/store/dmgp3qr5mk3pv3p33zdynh2vh0lk1bp2-file1.txt15662026/10/01 08:27:00 OK 20241026095416_initial_model.sql (116.6ms)15672026/10/01 08:27:00 OK 20241026095416_initial_model.sql (97.64ms)15682026/10/01 08:27:00 OK 20251210153512_drop_unused_gin_index.sql (14.19ms)15692026/10/01 08:27:00 OK 20251210153512_drop_unused_gin_index.sql (14.01ms)15702026/10/01 08:27:00 OK 20251218171726_add_pins.sql (14.48ms)15712026/10/01 08:27:00 OK 20251218171726_add_pins.sql (14.54ms)15722026/10/01 08:27:00 OK 20260628120000_add_object_size_and_stats.sql (12.08ms)15732026/10/01 08:27:00 OK 20260628120000_add_object_size_and_stats.sql (19.58ms)15742026/10/01 08:27:00 OK 20241026095416_initial_model.sql (89.01ms)15752026/10/01 08:27:00 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)15762026/10/01 08:27:00 OK 20260905000000_add_claims.sql (29.68ms)15772026/10/01 08:27:00 OK 20260905000000_add_claims.sql (22.24ms)15782026/10/01 08:27:00 OK 20251218171726_add_pins.sql (11.93ms)15792026/10/01 08:27:00 OK 20260920000000_drop_claims.sql (16.92ms)15802026/10/01 08:27:00 OK 20260920000000_drop_claims.sql (17.2ms)15812026/10/01 08:27:00 INFO Received push request method=POST path=/api/pushes15822026-10-01 08:27:01.004 UTC [86516] ERROR: relation "goose_db_version" does not exist at character 3615832026-10-01 08:27:01.004 UTC [86516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15842026/10/01 08:27:01 OK 20260628120000_add_object_size_and_stats.sql (26.02ms)15852026/10/01 08:27:01 OK 20260923120000_add_pushes.sql (10.92ms)15862026/10/01 08:27:01 OK 20260923120000_add_pushes.sql (11.17ms)15872026/10/01 08:27:01 goose: successfully migrated database to version: 2026092312000015882026/10/01 08:27:01 goose: successfully migrated database to version: 2026092312000015892026/10/01 08:27:01 OK 1_commit_pending_closure.sql (1ms)15902026/10/01 08:27:01 OK 1_commit_pending_closure.sql (1.01ms)15912026/10/01 08:27:01 OK 2_object_stats_trigger.sql (235.67µs)15922026/10/01 08:27:01 OK 2_object_stats_trigger.sql (239.04µs)15932026/10/01 08:27:01 OK 3_commit_push.sql (184.58µs)15942026/10/01 08:27:01 goose: up to current file version: 315952026/10/01 08:27:01 OK 3_commit_push.sql (207.38µs)15962026/10/01 08:27:01 goose: up to current file version: 315972026/10/01 08:27:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15982026/10/01 08:27:01 INFO Uploading dmgp3qr5mk3pv3p33zdynh2vh0lk1bp2-file1.txt (160B)15992026/10/01 08:27:01 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16002026/10/01 08:27:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16012026/10/01 08:27:01 INFO Signed narinfos id=1 count=116022026/10/01 08:27:01 WARN Failed to register uploaded object key=dmgp3qr5mk3pv3p33zdynh2vh0lk1bp2.ls error="server returned 404: 404 page not found\n"16032026/10/01 08:27:01 INFO Uploading 1 narinfos16042026/10/01 08:27:01 OK 20260905000000_add_claims.sql (47.98ms)16052026/10/01 08:27:01 OK 20260920000000_drop_claims.sql (14.87ms)16062026/10/01 08:27:01 INFO Received complete push request method=POST path=/api/pushes/1/complete16072026/10/01 08:27:01 WARN Failed to register uploaded object key=dmgp3qr5mk3pv3p33zdynh2vh0lk1bp2.narinfo error="server returned 404: 404 page not found\n"16082026/10/01 08:27:01 OK 20260923120000_add_pushes.sql (2.08ms)16092026/10/01 08:27:01 goose: successfully migrated database to version: 2026092312000016102026/10/01 08:27:01 OK 1_commit_pending_closure.sql (1.23ms)16112026/10/01 08:27:01 OK 2_object_stats_trigger.sql (215.04µs)16122026/10/01 08:27:01 OK 3_commit_push.sql (190.46µs)16132026/10/01 08:27:01 goose: up to current file version: 316142026/10/01 08:27:01 INFO Upload complete. (151ms)1615 metadata_upload_test.go:54: Retrieved narinfo from S3:1616 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestNARDeduplicationMetadataUploadBug474214115/001/store/dmgp3qr5mk3pv3p33zdynh2vh0lk1bp2-file1.txt1617 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1618 Compression: zstd1619 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1620 NarSize: 1601621 References: 1622 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1623 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1624 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1625 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16262026/10/01 08:27:01 OK 20241026095416_initial_model.sql (142.1ms)16272026/10/01 08:27:01 OK 20251210153512_drop_unused_gin_index.sql (14.22ms)1628 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-86274-2014532869/TestNARDeduplicationMetadataUploadBug474214115/001/store/ic3bnqq5j53ifg2nj70rwnbjn2kllq17-file2.txt16292026/10/01 08:27:01 OK 20251218171726_add_pins.sql (33.79ms)16302026/10/01 08:27:01 OK 20260628120000_add_object_size_and_stats.sql (32.05ms)16312026/10/01 08:27:01 WARN readiness check failed error="closed pool"1632--- PASS: TestService_readinessHandler (2.71s)1633=== CONT TestCommitRacingPendingCleanupKeepsObjects16342026/10/01 08:27:01 INFO Received push request method=POST path=/api/pushes16352026/10/01 08:27:01 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16362026/10/01 08:27:01 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16372026/10/01 08:27:01 INFO Signed narinfos id=2 count=116382026/10/01 08:27:01 INFO Uploading 1 narinfos16392026/10/01 08:27:01 WARN Failed to register uploaded object key=ic3bnqq5j53ifg2nj70rwnbjn2kllq17.ls error="server returned 404: 404 page not found\n"16402026/10/01 08:27:01 OK 20260905000000_add_claims.sql (49.22ms)16412026/10/01 08:27:01 INFO Received complete push request method=POST path=/api/pushes/2/complete16422026/10/01 08:27:01 WARN Failed to register uploaded object key=ic3bnqq5j53ifg2nj70rwnbjn2kllq17.narinfo error="server returned 404: 404 page not found\n"16432026/10/01 08:27:01 INFO Upload complete. (84ms)1644=== NAME TestNARDeduplicationMetadataUploadBug1645 metadata_upload_test.go:76: Retrieved narinfo from S3:1646 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestNARDeduplicationMetadataUploadBug474214115/001/store/ic3bnqq5j53ifg2nj70rwnbjn2kllq17-file2.txt1647 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1648 Compression: zstd1649 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1650 NarSize: 1601651 References: 1652 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1653 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1654 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1655 {"version":1,"root":{"type":"regular","size":44}}16562026/10/01 08:27:01 OK 20260920000000_drop_claims.sql (26.99ms)16572026/10/01 08:27:01 OK 20260923120000_add_pushes.sql (8.23ms)16582026/10/01 08:27:01 goose: successfully migrated database to version: 2026092312000016592026/10/01 08:27:01 OK 1_commit_pending_closure.sql (910.5µs)16602026/10/01 08:27:01 OK 2_object_stats_trigger.sql (206.17µs)16612026/10/01 08:27:01 OK 3_commit_push.sql (185.75µs)16622026/10/01 08:27:01 goose: up to current file version: 31663--- PASS: TestNARDeduplicationMetadataUploadBug (4.62s)1664=== CONT TestGCSweepSkipsPendingObjects1665--- PASS: TestReadProxyDisabled (3.07s)1666=== CONT TestPushWaitsForSweepHoldingRow16672026-10-01 08:27:01.687 UTC [86531] ERROR: relation "goose_db_version" does not exist at character 3616682026-10-01 08:27:01.687 UTC [86531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16692026-10-01 08:27:01.688 UTC [86530] ERROR: relation "goose_db_version" does not exist at character 3616702026-10-01 08:27:01.688 UTC [86530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1671--- PASS: TestService_healthCheckHandler (2.94s)1672=== CONT TestDeduplicatedObjectsRecordedAsPending16732026/10/01 08:27:01 OK 20241026095416_initial_model.sql (172.5ms)16742026/10/01 08:27:01 OK 20241026095416_initial_model.sql (172.89ms)16752026/10/01 08:27:01 OK 20251210153512_drop_unused_gin_index.sql (4.7ms)16762026/10/01 08:27:01 OK 20251210153512_drop_unused_gin_index.sql (4.79ms)16772026/10/01 08:27:01 OK 20251218171726_add_pins.sql (35.31ms)16782026/10/01 08:27:01 OK 20251218171726_add_pins.sql (35.18ms)16792026-10-01 08:27:01.975 UTC [86534] ERROR: relation "goose_db_version" does not exist at character 3616802026-10-01 08:27:01.975 UTC [86534] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16812026/10/01 08:27:01 OK 20260628120000_add_object_size_and_stats.sql (19.77ms)16822026/10/01 08:27:01 OK 20260628120000_add_object_size_and_stats.sql (20.52ms)16832026/10/01 08:27:02 OK 20260905000000_add_claims.sql (58.76ms)16842026/10/01 08:27:02 OK 20260905000000_add_claims.sql (60.62ms)16852026/10/01 08:27:02 OK 20260920000000_drop_claims.sql (55.25ms)16862026/10/01 08:27:02 OK 20260920000000_drop_claims.sql (56.64ms)16872026/10/01 08:27:02 OK 20260923120000_add_pushes.sql (17.29ms)16882026/10/01 08:27:02 goose: successfully migrated database to version: 2026092312000016892026/10/01 08:27:02 OK 20260923120000_add_pushes.sql (17.67ms)16902026/10/01 08:27:02 goose: successfully migrated database to version: 2026092312000016912026/10/01 08:27:02 OK 1_commit_pending_closure.sql (4.2ms)16922026/10/01 08:27:02 OK 1_commit_pending_closure.sql (4.65ms)16932026/10/01 08:27:02 OK 2_object_stats_trigger.sql (803.33µs)16942026/10/01 08:27:02 OK 2_object_stats_trigger.sql (816.75µs)16952026/10/01 08:27:02 OK 3_commit_push.sql (693.92µs)16962026/10/01 08:27:02 goose: up to current file version: 316972026/10/01 08:27:02 OK 3_commit_push.sql (728.67µs)16982026/10/01 08:27:02 goose: up to current file version: 316992026-10-01 08:27:02.239 UTC [86535] ERROR: relation "goose_db_version" does not exist at character 3617002026-10-01 08:27:02.239 UTC [86535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17012026/10/01 08:27:02 OK 20241026095416_initial_model.sql (273.69ms)17022026/10/01 08:27:02 OK 20251210153512_drop_unused_gin_index.sql (10.9ms)17032026/10/01 08:27:02 OK 20251218171726_add_pins.sql (34.97ms)17042026/10/01 08:27:02 OK 20260628120000_add_object_size_and_stats.sql (31.37ms)17052026/10/01 08:27:02 OK 20260905000000_add_claims.sql (60.24ms)17062026/10/01 08:27:02 INFO Received uploads request method=POST path=/api/pending_closures17072026/10/01 08:27:02 OK 20241026095416_initial_model.sql (160.58ms)17082026/10/01 08:27:02 OK 20260920000000_drop_claims.sql (29.96ms)17092026/10/01 08:27:02 OK 20251210153512_drop_unused_gin_index.sql (7.74ms)17102026/10/01 08:27:02 OK 20260923120000_add_pushes.sql (9.2ms)17112026/10/01 08:27:02 goose: successfully migrated database to version: 2026092312000017122026/10/01 08:27:02 OK 1_commit_pending_closure.sql (1.14ms)17132026/10/01 08:27:02 OK 2_object_stats_trigger.sql (281.08µs)17142026/10/01 08:27:02 OK 3_commit_push.sql (220.33µs)17152026/10/01 08:27:02 goose: up to current file version: 317162026/10/01 08:27:02 OK 20251218171726_add_pins.sql (17.66ms)17172026/10/01 08:27:02 OK 20260628120000_add_object_size_and_stats.sql (53.76ms)1718=== NAME TestPinProtectsFromGC1719 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-86274-2014532869/TestPinProtectsFromGC2069858757/001/store/mz6qpncraibmdxpwrrrc7a7amps2rz93-pinned-file.txt1720 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-86274-2014532869/TestPinProtectsFromGC2069858757/001/store/dz0yrl8p05lqnr4gaj1g1h94yfqkl7w6-unpinned-file.txt17212026/10/01 08:27:02 OK 20260905000000_add_claims.sql (46.33ms)17222026/10/01 08:27:02 OK 20260920000000_drop_claims.sql (25.98ms)17232026/10/01 08:27:02 OK 20260923120000_add_pushes.sql (19.65ms)17242026/10/01 08:27:02 goose: successfully migrated database to version: 2026092312000017252026/10/01 08:27:02 OK 1_commit_pending_closure.sql (1.87ms)17262026/10/01 08:27:02 OK 2_object_stats_trigger.sql (254.42µs)17272026/10/01 08:27:02 OK 3_commit_push.sql (450.96µs)17282026/10/01 08:27:02 goose: up to current file version: 317292026/10/01 08:27:02 INFO Received push request method=POST path=/api/pushes1730--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.97s)1731=== CONT TestSweepRechecksPendingAfterLocking17322026/10/01 08:27:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17332026/10/01 08:27:02 INFO Uploading mz6qpncraibmdxpwrrrc7a7amps2rz93-pinned-file.txt (128B)17342026/10/01 08:27:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17352026/10/01 08:27:02 WARN Failed to register uploaded object key=mz6qpncraibmdxpwrrrc7a7amps2rz93.ls error="server returned 404: 404 page not found\n"17362026/10/01 08:27:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17372026/10/01 08:27:02 INFO Signed narinfos id=1 count=117382026/10/01 08:27:02 INFO Uploading 1 narinfos17392026/10/01 08:27:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17402026/10/01 08:27:02 WARN Failed to register uploaded object key=mz6qpncraibmdxpwrrrc7a7amps2rz93.narinfo error="server returned 404: 404 page not found\n"17412026/10/01 08:27:02 INFO Upload complete. (143ms)1742--- PASS: TestCacheStatsHandler (2.95s)1743=== CONT TestPushDedupSurvivesConcurrentGC17442026/10/01 08:27:02 INFO Received push request method=POST path=/api/pushes17452026/10/01 08:27:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17462026/10/01 08:27:02 INFO Uploading dz0yrl8p05lqnr4gaj1g1h94yfqkl7w6-unpinned-file.txt (128B)17472026/10/01 08:27:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17482026/10/01 08:27:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17492026/10/01 08:27:02 WARN Failed to register uploaded object key=dz0yrl8p05lqnr4gaj1g1h94yfqkl7w6.ls error="server returned 404: 404 page not found\n"17502026/10/01 08:27:02 INFO Signed narinfos id=2 count=117512026/10/01 08:27:02 INFO Uploading 1 narinfos17522026/10/01 08:27:02 INFO Received complete push request method=POST path=/api/pushes/2/complete17532026/10/01 08:27:02 WARN Failed to register uploaded object key=dz0yrl8p05lqnr4gaj1g1h94yfqkl7w6.narinfo error="server returned 404: 404 page not found\n"17542026/10/01 08:27:02 INFO Upload complete. (100ms)17552026/10/01 08:27:02 INFO Received create pin request method=POST path=/api/pins/myapp17562026/10/01 08:27:02 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-86274-2014532869/TestPinProtectsFromGC2069858757/001/store/mz6qpncraibmdxpwrrrc7a7amps2rz93-pinned-file.txt narinfo_key=mz6qpncraibmdxpwrrrc7a7amps2rz93.narinfo17572026/10/01 08:27:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures17582026/10/01 08:27:02 INFO Garbage collection started17592026/10/01 08:27:02 INFO Aborted multipart uploads count=017602026/10/01 08:27:02 WARN Force mode enabled - objects will be deleted immediately without grace period17612026/10/01 08:27:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=017622026/10/01 08:27:03 INFO Vacuumed table table=pending_closures17632026/10/01 08:27:03 INFO Aborted multipart uploads count=017642026/10/01 08:27:03 WARN Force mode enabled - objects will be deleted immediately without grace period17652026/10/01 08:27:03 INFO Vacuumed table table=pending_objects17662026/10/01 08:27:03 INFO Vacuumed table table=multipart_uploads17672026/10/01 08:27:03 INFO Vacuumed table table=closures17682026/10/01 08:27:03 INFO Vacuumed table table=objects17692026/10/01 08:27:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=017702026/10/01 08:27:03 INFO Vacuumed table table=pending_closures17712026/10/01 08:27:03 INFO Vacuumed table table=pending_objects17722026/10/01 08:27:03 INFO Vacuumed table table=multipart_uploads17732026/10/01 08:27:03 INFO Vacuumed table table=closures17742026/10/01 08:27:03 INFO Vacuumed table table=objects1775--- PASS: TestGCSweepDeliversEachKeyOnce (3.10s)1776=== CONT TestGetExistingObjectsLocksRows17772026/10/01 08:27:03 INFO Received uploads request method=POST path=/api/pending_closures17782026-10-01 08:27:03.292 UTC [86561] ERROR: relation "goose_db_version" does not exist at character 3617792026-10-01 08:27:03.292 UTC [86561] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1780=== NAME TestOrphanedObjectsGCStressTest1781 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1782--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.88s)1783=== CONT TestGCMetrics17842026-10-01 08:27:03.368 UTC [86565] ERROR: relation "goose_db_version" does not exist at character 3617852026-10-01 08:27:03.368 UTC [86565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17862026-10-01 08:27:03.377 UTC [86566] ERROR: relation "goose_db_version" does not exist at character 3617872026-10-01 08:27:03.377 UTC [86566] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1788=== NAME TestOrphanedObjectsGCStressTest1789 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17902026-10-01 08:27:03.390 UTC [86567] ERROR: relation "goose_db_version" does not exist at character 3617912026-10-01 08:27:03.390 UTC [86567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17922026/10/01 08:27:03 OK 20241026095416_initial_model.sql (52.15ms)17932026/10/01 08:27:03 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)17942026/10/01 08:27:03 OK 20251218171726_add_pins.sql (1.44ms)17952026/10/01 08:27:03 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)17962026/10/01 08:27:03 OK 20260905000000_add_claims.sql (3.24ms)17972026/10/01 08:27:03 OK 20241026095416_initial_model.sql (13.63ms)17982026/10/01 08:27:03 OK 20241026095416_initial_model.sql (10.78ms)17992026/10/01 08:27:03 OK 20260920000000_drop_claims.sql (5.51ms)18002026/10/01 08:27:03 OK 20251210153512_drop_unused_gin_index.sql (556.83µs)18012026/10/01 08:27:03 OK 20251210153512_drop_unused_gin_index.sql (632.79µs)18022026/10/01 08:27:03 OK 20241026095416_initial_model.sql (9.13ms)18032026/10/01 08:27:03 OK 20251210153512_drop_unused_gin_index.sql (488.42µs)18042026/10/01 08:27:03 OK 20251218171726_add_pins.sql (824.79µs)18052026/10/01 08:27:03 OK 20251218171726_add_pins.sql (886.33µs)18062026/10/01 08:27:03 OK 20251218171726_add_pins.sql (842.54µs)18072026/10/01 08:27:03 OK 20260923120000_add_pushes.sql (4.24ms)18082026/10/01 08:27:03 goose: successfully migrated database to version: 2026092312000018092026/10/01 08:27:03 OK 1_commit_pending_closure.sql (1.15ms)18102026/10/01 08:27:03 OK 2_object_stats_trigger.sql (222.71µs)18112026/10/01 08:27:03 OK 3_commit_push.sql (162.63µs)18122026/10/01 08:27:03 goose: up to current file version: 318132026/10/01 08:27:03 OK 20260628120000_add_object_size_and_stats.sql (21.03ms)18142026/10/01 08:27:03 OK 20260628120000_add_object_size_and_stats.sql (20.62ms)18152026/10/01 08:27:03 OK 20260628120000_add_object_size_and_stats.sql (27.98ms)18162026/10/01 08:27:03 OK 20260905000000_add_claims.sql (25.36ms)18172026/10/01 08:27:03 OK 20260905000000_add_claims.sql (25.94ms)18182026/10/01 08:27:03 OK 20260905000000_add_claims.sql (33.26ms)18192026/10/01 08:27:03 OK 20260920000000_drop_claims.sql (8.98ms)18202026/10/01 08:27:03 OK 20260920000000_drop_claims.sql (2.3ms)18212026/10/01 08:27:03 OK 20260923120000_add_pushes.sql (1.24ms)18222026/10/01 08:27:03 goose: successfully migrated database to version: 2026092312000018232026/10/01 08:27:03 OK 20260920000000_drop_claims.sql (2.17ms)18242026/10/01 08:27:03 OK 1_commit_pending_closure.sql (1.26ms)18252026/10/01 08:27:03 OK 2_object_stats_trigger.sql (218.58µs)18262026/10/01 08:27:03 OK 3_commit_push.sql (180.13µs)18272026/10/01 08:27:03 goose: up to current file version: 318282026/10/01 08:27:03 OK 20260923120000_add_pushes.sql (8.77ms)18292026/10/01 08:27:03 goose: successfully migrated database to version: 2026092312000018302026/10/01 08:27:03 OK 20260923120000_add_pushes.sql (8.37ms)18312026/10/01 08:27:03 goose: successfully migrated database to version: 2026092312000018322026/10/01 08:27:03 OK 1_commit_pending_closure.sql (1.22ms)18332026/10/01 08:27:03 OK 1_commit_pending_closure.sql (1.18ms)18342026/10/01 08:27:03 OK 2_object_stats_trigger.sql (218.08µs)18352026/10/01 08:27:03 OK 2_object_stats_trigger.sql (218.58µs)18362026/10/01 08:27:03 OK 3_commit_push.sql (183.46µs)18372026/10/01 08:27:03 goose: up to current file version: 318382026/10/01 08:27:03 OK 3_commit_push.sql (186.75µs)18392026/10/01 08:27:03 goose: up to current file version: 318402026/10/01 08:27:03 INFO Aborted multipart uploads count=018412026/10/01 08:27:03 WARN Force mode enabled - objects will be deleted immediately without grace period18422026/10/01 08:27:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018432026/10/01 08:27:03 INFO Vacuumed table table=pending_closures18442026/10/01 08:27:03 INFO Vacuumed table table=pending_objects18452026/10/01 08:27:03 INFO Vacuumed table table=multipart_uploads18462026/10/01 08:27:03 INFO Vacuumed table table=closures18472026/10/01 08:27:03 INFO Vacuumed table table=objects1848--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.61s)1849=== CONT TestGCBugBareHashReferences18502026/10/01 08:27:03 INFO Received uploads request method=POST path=/api/pending_closures18512026/10/01 08:27:04 INFO Received uploads request method=POST path=/api/pending_closures18522026/10/01 08:27:04 INFO Aborted multipart uploads count=018532026/10/01 08:27:04 WARN Force mode enabled - objects will be deleted immediately without grace period18542026/10/01 08:27:04 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=018552026/10/01 08:27:04 INFO Vacuumed table table=pending_closures18562026/10/01 08:27:04 INFO Vacuumed table table=pending_objects18572026/10/01 08:27:04 INFO Vacuumed table table=multipart_uploads18582026/10/01 08:27:04 INFO Vacuumed table table=closures18592026/10/01 08:27:04 INFO Vacuumed table table=objects1860--- PASS: TestPushWaitsForSweepHoldingRow (2.88s)1861=== CONT TestRegisterCompletedObjectNeedsPendingRow1862--- PASS: TestGCSweepSkipsPendingObjects (3.06s)1863=== CONT TestSweepSkipsRowsLockedByPush18642026/10/01 08:27:04 INFO Received uploads request method=POST path=/api/pending_closures1865--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.75s)1866=== CONT TestLeadEndsOnShutdown18672026-10-01 08:27:04.680 UTC [86581] ERROR: relation "goose_db_version" does not exist at character 3618682026-10-01 08:27:04.680 UTC [86581] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18692026-10-01 08:27:04.718 UTC [86582] ERROR: relation "goose_db_version" does not exist at character 3618702026-10-01 08:27:04.718 UTC [86582] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18712026/10/01 08:27:04 OK 20241026095416_initial_model.sql (48.74ms)18722026-10-01 08:27:04.788 UTC [86583] ERROR: relation "goose_db_version" does not exist at character 3618732026-10-01 08:27:04.788 UTC [86583] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18742026/10/01 08:27:04 OK 20251210153512_drop_unused_gin_index.sql (894.25µs)18752026/10/01 08:27:04 OK 20251218171726_add_pins.sql (2.4ms)18762026/10/01 08:27:04 OK 20241026095416_initial_model.sql (20.57ms)18772026/10/01 08:27:04 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)18782026/10/01 08:27:04 OK 20260628120000_add_object_size_and_stats.sql (5.27ms)18792026/10/01 08:27:04 OK 20251218171726_add_pins.sql (2.81ms)18802026-10-01 08:27:04.800 UTC [86584] ERROR: relation "goose_db_version" does not exist at character 3618812026-10-01 08:27:04.800 UTC [86584] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18822026/10/01 08:27:04 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)18832026/10/01 08:27:04 OK 20260905000000_add_claims.sql (4.3ms)18842026/10/01 08:27:04 OK 20260920000000_drop_claims.sql (1.23ms)18852026/10/01 08:27:04 OK 20260923120000_add_pushes.sql (1.7ms)18862026/10/01 08:27:04 goose: successfully migrated database to version: 2026092312000018872026/10/01 08:27:04 OK 20260905000000_add_claims.sql (4.34ms)18882026/10/01 08:27:04 OK 1_commit_pending_closure.sql (2.06ms)18892026/10/01 08:27:04 OK 2_object_stats_trigger.sql (541.08µs)18902026/10/01 08:27:04 OK 20260920000000_drop_claims.sql (1.74ms)18912026/10/01 08:27:04 OK 3_commit_push.sql (499.5µs)18922026/10/01 08:27:04 goose: up to current file version: 318932026/10/01 08:27:04 OK 20260923120000_add_pushes.sql (1.44ms)18942026/10/01 08:27:04 goose: successfully migrated database to version: 2026092312000018952026/10/01 08:27:04 OK 20241026095416_initial_model.sql (12.59ms)18962026/10/01 08:27:04 OK 1_commit_pending_closure.sql (1.93ms)18972026/10/01 08:27:04 OK 2_object_stats_trigger.sql (273.92µs)18982026/10/01 08:27:04 OK 3_commit_push.sql (274.96µs)18992026/10/01 08:27:04 goose: up to current file version: 319002026/10/01 08:27:04 OK 20251210153512_drop_unused_gin_index.sql (11.29ms)19012026/10/01 08:27:04 OK 20251218171726_add_pins.sql (12.81ms)19022026/10/01 08:27:04 OK 20260628120000_add_object_size_and_stats.sql (39.42ms)19032026/10/01 08:27:04 OK 20260905000000_add_claims.sql (54.07ms)19042026/10/01 08:27:04 OK 20241026095416_initial_model.sql (135.04ms)19052026/10/01 08:27:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01906=== NAME TestPinProtectsFromGC1907 client_integration_test.go:794: Pin successfully protected closure from garbage collection19082026/10/01 08:27:04 OK 20251210153512_drop_unused_gin_index.sql (13.85ms)19092026/10/01 08:27:04 OK 20260920000000_drop_claims.sql (41.68ms)19102026/10/01 08:27:04 OK 20260923120000_add_pushes.sql (20.69ms)19112026/10/01 08:27:04 goose: successfully migrated database to version: 2026092312000019122026/10/01 08:27:04 OK 20251218171726_add_pins.sql (33.07ms)19132026/10/01 08:27:04 OK 1_commit_pending_closure.sql (3.51ms)19142026/10/01 08:27:04 OK 2_object_stats_trigger.sql (674.29µs)19152026/10/01 08:27:04 OK 3_commit_push.sql (439.88µs)19162026/10/01 08:27:04 goose: up to current file version: 31917--- PASS: TestPinProtectsFromGC (5.73s)1918=== CONT TestLeadElectsOneAndHandsOver19192026/10/01 08:27:05 OK 20260628120000_add_object_size_and_stats.sql (36.44ms)19202026/10/01 08:27:05 OK 20260905000000_add_claims.sql (43.39ms)19212026/10/01 08:27:05 OK 20260920000000_drop_claims.sql (24.58ms)19222026/10/01 08:27:05 OK 20260923120000_add_pushes.sql (17.34ms)19232026/10/01 08:27:05 goose: successfully migrated database to version: 2026092312000019242026/10/01 08:27:05 OK 1_commit_pending_closure.sql (3.13ms)19252026/10/01 08:27:05 OK 2_object_stats_trigger.sql (602.33µs)19262026/10/01 08:27:05 OK 3_commit_push.sql (432.96µs)19272026/10/01 08:27:05 goose: up to current file version: 319282026/10/01 08:27:05 INFO Aborted multipart uploads count=019292026/10/01 08:27:05 WARN Force mode enabled - objects will be deleted immediately without grace period19302026/10/01 08:27:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019312026/10/01 08:27:05 INFO Vacuumed table table=pending_closures19322026/10/01 08:27:05 INFO Vacuumed table table=pending_objects19332026/10/01 08:27:05 INFO Vacuumed table table=multipart_uploads19342026/10/01 08:27:05 INFO Vacuumed table table=closures19352026/10/01 08:27:05 INFO Vacuumed table table=objects1936--- PASS: TestSweepRechecksPendingAfterLocking (2.55s)1937=== CONT TestResolveDBConnectionString1938=== RUN TestResolveDBConnectionString/flag_wins1939=== PAUSE TestResolveDBConnectionString/flag_wins1940=== RUN TestResolveDBConnectionString/file_when_flag_empty1941=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1942=== RUN TestResolveDBConnectionString/missing_file_is_an_error1943=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1944=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1945=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1946=== RUN TestResolveDBConnectionString/nothing_configured1947=== PAUSE TestResolveDBConnectionString/nothing_configured1948=== CONT TestClientFallsBackToClosures19492026/10/01 08:27:05 INFO Received uploads request method=POST path=/api/pending_closures19502026/10/01 08:27:05 INFO Aborted multipart uploads count=019512026/10/01 08:27:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019522026/10/01 08:27:05 INFO Vacuumed table table=pending_closures19532026/10/01 08:27:05 INFO Vacuumed table table=pending_objects19542026/10/01 08:27:05 INFO Vacuumed table table=multipart_uploads1955--- PASS: TestGetExistingObjectsLocksRows (2.51s)1956=== CONT TestClientPushesUseOnePush19572026/10/01 08:27:05 INFO Vacuumed table table=closures19582026/10/01 08:27:05 INFO Vacuumed table table=objects19592026/10/01 08:27:05 INFO Aborted multipart uploads count=019602026/10/01 08:27:05 WARN Force mode enabled - objects will be deleted immediately without grace period19612026/10/01 08:27:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019622026/10/01 08:27:05 INFO Vacuumed table table=pending_closures19632026/10/01 08:27:05 INFO Vacuumed table table=pending_objects19642026/10/01 08:27:05 INFO Vacuumed table table=multipart_uploads19652026/10/01 08:27:05 INFO Vacuumed table table=closures19662026/10/01 08:27:05 INFO Vacuumed table table=objects1967--- PASS: TestPushDedupSurvivesConcurrentGC (3.08s)1968=== CONT TestService_AuthMiddleware_OIDC19692026/10/01 08:27:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60085/oidc19702026/10/01 08:27:06 INFO Aborted multipart uploads count=019712026/10/01 08:27:06 WARN Force mode enabled - objects will be deleted immediately without grace period19722026/10/01 08:27:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019732026/10/01 08:27:06 INFO Vacuumed table table=pending_closures19742026/10/01 08:27:06 INFO Vacuumed table table=pending_objects19752026/10/01 08:27:06 INFO Vacuumed table table=multipart_uploads19762026/10/01 08:27:06 INFO Vacuumed table table=closures19772026/10/01 08:27:06 INFO Vacuumed table table=objects1978--- PASS: TestGCMetrics (2.69s)1979=== CONT TestReadProxyHead19802026-10-01 08:27:06.031 UTC [86596] ERROR: relation "goose_db_version" does not exist at character 3619812026-10-01 08:27:06.031 UTC [86596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1982=== NAME TestOrphanedObjectsGCStressTest1983 orphaned_objects_gc_test.go:509: Stress test completed successfully:1984 orphaned_objects_gc_test.go:510: - Active objects preserved: 201985 orphaned_objects_gc_test.go:511: - Objects deleted: 2101986 orphaned_objects_gc_test.go:512: - Total GC'd: 2101987--- PASS: TestOrphanedObjectsGCStressTest (12.13s)1988=== CONT TestCacheConfigHandler1989=== RUN TestCacheConfigHandler/full_config,_no_issuer1990=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1991=== RUN TestCacheConfigHandler/no_cache_url_configured1992=== PAUSE TestCacheConfigHandler/no_cache_url_configured1993=== RUN TestCacheConfigHandler/no_signing_keys1994=== PAUSE TestCacheConfigHandler/no_signing_keys1995=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1996=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1997=== CONT TestClientIntegration19982026-10-01 08:27:06.155 UTC [86602] ERROR: relation "goose_db_version" does not exist at character 3619992026-10-01 08:27:06.155 UTC [86602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20002026-10-01 08:27:06.155 UTC [86601] ERROR: relation "goose_db_version" does not exist at character 3620012026-10-01 08:27:06.155 UTC [86601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20022026/10/01 08:27:06 OK 20241026095416_initial_model.sql (140.14ms)20032026/10/01 08:27:06 OK 20251210153512_drop_unused_gin_index.sql (6.48ms)20042026-10-01 08:27:06.235 UTC [86605] ERROR: relation "goose_db_version" does not exist at character 3620052026-10-01 08:27:06.235 UTC [86605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20062026/10/01 08:27:06 OK 20251218171726_add_pins.sql (23.65ms)20072026/10/01 08:27:06 OK 20260628120000_add_object_size_and_stats.sql (5.74ms)20082026/10/01 08:27:06 OK 20241026095416_initial_model.sql (39.26ms)20092026/10/01 08:27:06 OK 20251210153512_drop_unused_gin_index.sql (611.83µs)20102026/10/01 08:27:06 OK 20260905000000_add_claims.sql (4.08ms)20112026/10/01 08:27:06 OK 20241026095416_initial_model.sql (41.84ms)20122026/10/01 08:27:06 OK 20251210153512_drop_unused_gin_index.sql (432.92µs)20132026/10/01 08:27:06 OK 20260920000000_drop_claims.sql (900.42µs)20142026/10/01 08:27:06 OK 20251218171726_add_pins.sql (2.26ms)20152026/10/01 08:27:06 OK 20260923120000_add_pushes.sql (497.58µs)20162026/10/01 08:27:06 goose: successfully migrated database to version: 2026092312000020172026/10/01 08:27:06 OK 20251218171726_add_pins.sql (896.71µs)20182026/10/01 08:27:06 OK 1_commit_pending_closure.sql (1.37ms)20192026/10/01 08:27:06 OK 2_object_stats_trigger.sql (314.33µs)20202026/10/01 08:27:06 OK 3_commit_push.sql (202.42µs)20212026/10/01 08:27:06 goose: up to current file version: 320222026/10/01 08:27:06 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)20232026/10/01 08:27:06 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)20242026/10/01 08:27:06 OK 20260905000000_add_claims.sql (12.97ms)20252026/10/01 08:27:06 OK 20241026095416_initial_model.sql (36.59ms)20262026/10/01 08:27:06 OK 20260905000000_add_claims.sql (29.2ms)20272026/10/01 08:27:06 OK 20260920000000_drop_claims.sql (17.27ms)20282026/10/01 08:27:06 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)20292026/10/01 08:27:06 OK 20260923120000_add_pushes.sql (2.29ms)20302026/10/01 08:27:06 goose: successfully migrated database to version: 2026092312000020312026/10/01 08:27:06 OK 20260920000000_drop_claims.sql (3.03ms)20322026/10/01 08:27:06 OK 20251218171726_add_pins.sql (2.95ms)20332026/10/01 08:27:06 OK 1_commit_pending_closure.sql (1.83ms)20342026/10/01 08:27:06 OK 2_object_stats_trigger.sql (441.25µs)20352026/10/01 08:27:06 OK 3_commit_push.sql (181.88µs)20362026/10/01 08:27:06 goose: up to current file version: 320372026/10/01 08:27:06 OK 20260923120000_add_pushes.sql (10.48ms)20382026/10/01 08:27:06 goose: successfully migrated database to version: 2026092312000020392026/10/01 08:27:06 OK 1_commit_pending_closure.sql (949.38µs)20402026/10/01 08:27:06 OK 2_object_stats_trigger.sql (254.21µs)20412026/10/01 08:27:06 OK 3_commit_push.sql (175.83µs)20422026/10/01 08:27:06 goose: up to current file version: 320432026/10/01 08:27:06 OK 20260628120000_add_object_size_and_stats.sql (19ms)20442026/10/01 08:27:06 OK 20260905000000_add_claims.sql (14.44ms)20452026/10/01 08:27:06 OK 20260920000000_drop_claims.sql (2.02ms)20462026/10/01 08:27:06 OK 20260923120000_add_pushes.sql (8.33ms)20472026/10/01 08:27:06 goose: successfully migrated database to version: 2026092312000020482026/10/01 08:27:06 OK 1_commit_pending_closure.sql (1.08ms)20492026/10/01 08:27:06 OK 2_object_stats_trigger.sql (240.25µs)20502026/10/01 08:27:06 OK 3_commit_push.sql (186.58µs)20512026/10/01 08:27:06 goose: up to current file version: 320522026-10-01 08:27:06.782 UTC [86606] ERROR: relation "goose_db_version" does not exist at character 3620532026-10-01 08:27:06.782 UTC [86606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2054--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.35s)2055=== CONT TestService_ReadScope_PublicByDefault2056--- PASS: TestGCBugBareHashReferences (2.92s)2057=== CONT TestClientWithDependencies20582026/10/01 08:27:07 OK 20241026095416_initial_model.sql (152.24ms)20592026/10/01 08:27:07 OK 20251210153512_drop_unused_gin_index.sql (8.33ms)20602026/10/01 08:27:07 OK 20251218171726_add_pins.sql (39.2ms)20612026/10/01 08:27:07 OK 20260628120000_add_object_size_and_stats.sql (49.96ms)20622026/10/01 08:27:07 INFO Aborted multipart uploads count=020632026/10/01 08:27:07 WARN Force mode enabled - objects will be deleted immediately without grace period20642026/10/01 08:27:07 OK 20260905000000_add_claims.sql (108.54ms)20652026/10/01 08:27:07 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020662026/10/01 08:27:07 INFO Vacuumed table table=pending_closures20672026/10/01 08:27:07 INFO Vacuumed table table=pending_objects20682026/10/01 08:27:07 INFO Vacuumed table table=multipart_uploads20692026/10/01 08:27:07 INFO Vacuumed table table=closures20702026/10/01 08:27:07 OK 20260920000000_drop_claims.sql (29.6ms)20712026/10/01 08:27:07 INFO Vacuumed table table=objects20722026/10/01 08:27:07 INFO Aborted multipart uploads count=020732026/10/01 08:27:07 WARN Force mode enabled - objects will be deleted immediately without grace period20742026/10/01 08:27:07 OK 20260923120000_add_pushes.sql (32.12ms)20752026/10/01 08:27:07 goose: successfully migrated database to version: 2026092312000020762026/10/01 08:27:07 OK 1_commit_pending_closure.sql (3.36ms)20772026/10/01 08:27:07 OK 2_object_stats_trigger.sql (910.21µs)20782026/10/01 08:27:07 OK 3_commit_push.sql (1.07ms)20792026/10/01 08:27:07 goose: up to current file version: 320802026/10/01 08:27:07 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=020812026/10/01 08:27:07 INFO Vacuumed table table=pending_closures20822026/10/01 08:27:07 INFO Vacuumed table table=pending_objects20832026/10/01 08:27:07 INFO Vacuumed table table=multipart_uploads20842026/10/01 08:27:07 INFO Vacuumed table table=closures20852026/10/01 08:27:07 INFO Vacuumed table table=objects2086--- PASS: TestSweepSkipsRowsLockedByPush (2.89s)2087=== CONT TestService_RequireScope_OIDC20882026/10/01 08:27:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60095/oidc20892026/10/01 08:27:07 INFO lead: acquired remote=192.0.2.1:123420902026/10/01 08:27:07 INFO lead: released remote=192.0.2.1:12342091--- PASS: TestLeadEndsOnShutdown (2.90s)2092=== CONT TestClientMultipleUploads20932026-10-01 08:27:07.578 UTC [86614] ERROR: relation "goose_db_version" does not exist at character 3620942026-10-01 08:27:07.578 UTC [86614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20952026/10/01 08:27:07 INFO lead: acquired remote=192.0.2.1:123420962026-10-01 08:27:07.827 UTC [86618] ERROR: relation "goose_db_version" does not exist at character 3620972026-10-01 08:27:07.827 UTC [86618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20982026/10/01 08:27:07 OK 20241026095416_initial_model.sql (219.94ms)20992026/10/01 08:27:07 OK 20251210153512_drop_unused_gin_index.sql (23.34ms)21002026/10/01 08:27:07 OK 20251218171726_add_pins.sql (49.18ms)21012026/10/01 08:27:07 OK 20260628120000_add_object_size_and_stats.sql (38.32ms)21022026/10/01 08:27:07 INFO lead: released remote=192.0.2.1:123421032026-10-01 08:27:07.979 UTC [86621] ERROR: relation "goose_db_version" does not exist at character 3621042026-10-01 08:27:07.979 UTC [86621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21052026-10-01 08:27:07.981 UTC [86620] ERROR: relation "goose_db_version" does not exist at character 3621062026-10-01 08:27:07.981 UTC [86620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21072026/10/01 08:27:07 OK 20260905000000_add_claims.sql (27.72ms)21082026/10/01 08:27:08 OK 20260920000000_drop_claims.sql (22.81ms)21092026/10/01 08:27:08 OK 20241026095416_initial_model.sql (83.88ms)21102026/10/01 08:27:08 OK 20260923120000_add_pushes.sql (5.1ms)21112026/10/01 08:27:08 goose: successfully migrated database to version: 2026092312000021122026/10/01 08:27:08 INFO lead: acquired remote=192.0.2.1:123421132026/10/01 08:27:08 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)21142026/10/01 08:27:08 OK 1_commit_pending_closure.sql (4.22ms)21152026/10/01 08:27:08 OK 2_object_stats_trigger.sql (980.08µs)21162026/10/01 08:27:08 OK 3_commit_push.sql (522.04µs)21172026/10/01 08:27:08 goose: up to current file version: 321182026/10/01 08:27:08 INFO lead: released remote=192.0.2.1:12342119--- PASS: TestLeadElectsOneAndHandsOver (3.00s)2120=== CONT TestReadProxyConditionalGet21212026/10/01 08:27:08 OK 20251218171726_add_pins.sql (26.36ms)21222026/10/01 08:27:08 OK 20260628120000_add_object_size_and_stats.sql (25.17ms)21232026/10/01 08:27:08 OK 20260905000000_add_claims.sql (50.86ms)21242026-10-01 08:27:08.128 UTC [86625] ERROR: relation "goose_db_version" does not exist at character 3621252026-10-01 08:27:08.128 UTC [86625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21262026/10/01 08:27:08 OK 20241026095416_initial_model.sql (130.97ms)21272026/10/01 08:27:08 OK 20241026095416_initial_model.sql (144.53ms)21282026/10/01 08:27:08 OK 20251210153512_drop_unused_gin_index.sql (14.82ms)21292026/10/01 08:27:08 OK 20260920000000_drop_claims.sql (38.79ms)21302026/10/01 08:27:08 OK 20251210153512_drop_unused_gin_index.sql (13.72ms)21312026/10/01 08:27:08 OK 20260923120000_add_pushes.sql (27.15ms)21322026/10/01 08:27:08 goose: successfully migrated database to version: 2026092312000021332026/10/01 08:27:08 OK 1_commit_pending_closure.sql (5.68ms)21342026/10/01 08:27:08 OK 2_object_stats_trigger.sql (961.88µs)21352026/10/01 08:27:08 OK 3_commit_push.sql (660.25µs)21362026/10/01 08:27:08 goose: up to current file version: 321372026/10/01 08:27:08 OK 20251218171726_add_pins.sql (51.26ms)21382026/10/01 08:27:08 OK 20251218171726_add_pins.sql (38.83ms)21392026/10/01 08:27:08 OK 20260628120000_add_object_size_and_stats.sql (42.97ms)21402026/10/01 08:27:08 OK 20260628120000_add_object_size_and_stats.sql (43.1ms)21412026/10/01 08:27:08 OK 20260905000000_add_claims.sql (52.39ms)21422026/10/01 08:27:08 OK 20260905000000_add_claims.sql (67.34ms)21432026/10/01 08:27:08 OK 20260920000000_drop_claims.sql (56.66ms)21442026/10/01 08:27:08 OK 20260920000000_drop_claims.sql (42.22ms)21452026/10/01 08:27:08 OK 20260923120000_add_pushes.sql (14.49ms)21462026/10/01 08:27:08 goose: successfully migrated database to version: 2026092312000021472026/10/01 08:27:08 OK 1_commit_pending_closure.sql (2.56ms)21482026/10/01 08:27:08 OK 2_object_stats_trigger.sql (585.29µs)21492026/10/01 08:27:08 OK 3_commit_push.sql (418.33µs)21502026/10/01 08:27:08 goose: up to current file version: 321512026/10/01 08:27:08 OK 20260923120000_add_pushes.sql (20.39ms)21522026/10/01 08:27:08 goose: successfully migrated database to version: 2026092312000021532026/10/01 08:27:08 OK 1_commit_pending_closure.sql (2.22ms)21542026/10/01 08:27:08 OK 2_object_stats_trigger.sql (532.17µs)21552026/10/01 08:27:08 OK 3_commit_push.sql (354.29µs)21562026/10/01 08:27:08 goose: up to current file version: 321572026/10/01 08:27:08 OK 20241026095416_initial_model.sql (197.12ms)21582026/10/01 08:27:08 OK 20251210153512_drop_unused_gin_index.sql (16.2ms)21592026/10/01 08:27:08 OK 20251218171726_add_pins.sql (18.64ms)21602026/10/01 08:27:08 OK 20260628120000_add_object_size_and_stats.sql (41.87ms)21612026/10/01 08:27:08 OK 20260905000000_add_claims.sql (78.04ms)21622026/10/01 08:27:08 OK 20260920000000_drop_claims.sql (34.43ms)21632026/10/01 08:27:08 OK 20260923120000_add_pushes.sql (10.5ms)21642026/10/01 08:27:08 goose: successfully migrated database to version: 2026092312000021652026/10/01 08:27:08 OK 1_commit_pending_closure.sql (3.12ms)21662026/10/01 08:27:08 OK 2_object_stats_trigger.sql (566.92µs)21672026/10/01 08:27:08 OK 3_commit_push.sql (397.42µs)21682026/10/01 08:27:08 goose: up to current file version: 32169--- PASS: TestReadProxyHead (2.90s)2170=== CONT TestService_AuthMiddleware_MTLSProxyHeader21712026/10/01 08:27:08 INFO Received uploads request method=POST path=/api/pending_closures21722026/10/01 08:27:08 INFO Received uploads request method=POST path=/api/pending_closures21732026/10/01 08:27:08 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21742026/10/01 08:27:08 INFO Uploading r2mvi89kkg5izqzg597h7fy6bfx8izmj-a (248B)21752026/10/01 08:27:08 INFO Uploading yh0i6mxnk5b9vr1x1kz4ns7qvngpb6nd-shared-dep (136B)21762026/10/01 08:27:08 WARN Failed to register uploaded object key=nar/0aa2gp6ygksgyjqlglkywmkncknla1jyn6r9bxpilr4d5z0hsl9x.nar.zst error="server returned 404: 404 page not found\n"21772026/10/01 08:27:08 WARN Failed to register uploaded object key=00qkfgl8s2h9l7mxn4vg9pawrdi74y1s.ls error="server returned 404: 404 page not found\n"21782026/10/01 08:27:08 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21792026/10/01 08:27:08 WARN Failed to register uploaded object key=r2mvi89kkg5izqzg597h7fy6bfx8izmj.ls error="server returned 404: 404 page not found\n"21802026/10/01 08:27:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21812026/10/01 08:27:08 WARN Failed to register uploaded object key=yh0i6mxnk5b9vr1x1kz4ns7qvngpb6nd.ls error="server returned 404: 404 page not found\n"21822026/10/01 08:27:08 INFO Signed narinfos id=1 count=221832026/10/01 08:27:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21842026/10/01 08:27:08 INFO Signed narinfos id=2 count=221852026/10/01 08:27:08 INFO Uploading 4 narinfos21862026/10/01 08:27:09 WARN Failed to register uploaded object key=r2mvi89kkg5izqzg597h7fy6bfx8izmj.narinfo error="server returned 404: 404 page not found\n"21872026/10/01 08:27:09 WARN Failed to register uploaded object key=yh0i6mxnk5b9vr1x1kz4ns7qvngpb6nd.narinfo error="server returned 404: 404 page not found\n"21882026/10/01 08:27:09 WARN Failed to register uploaded object key=00qkfgl8s2h9l7mxn4vg9pawrdi74y1s.narinfo error="server returned 404: 404 page not found\n"21892026/10/01 08:27:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21902026/10/01 08:27:09 WARN Failed to register uploaded object key=yh0i6mxnk5b9vr1x1kz4ns7qvngpb6nd.narinfo error="server returned 404: 404 page not found\n"21912026/10/01 08:27:09 INFO Completed upload id=121922026/10/01 08:27:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21932026/10/01 08:27:09 INFO Completed upload id=221942026/10/01 08:27:09 INFO Upload complete. (215ms)2195=== NAME TestClientFallsBackToClosures2196 client_pushes_test.go:112: Retrieved narinfo from S3:2197 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientFallsBackToClosures1150879492/001/store/yh0i6mxnk5b9vr1x1kz4ns7qvngpb6nd-shared-dep2198 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2199 Compression: zstd2200 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822201 NarSize: 1362202 References: 2203 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2204 client_pushes_test.go:112: Retrieved narinfo from S3:2205 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientFallsBackToClosures1150879492/001/store/r2mvi89kkg5izqzg597h7fy6bfx8izmj-a2206 URL: nar/0aa2gp6ygksgyjqlglkywmkncknla1jyn6r9bxpilr4d5z0hsl9x.nar.zst2207 Compression: zstd2208 NarHash: sha256:0aa2gp6ygksgyjqlglkywmkncknla1jyn6r9bxpilr4d5z0hsl9x2209 NarSize: 2482210 References: /nix/var/nix/builds/nix-86274-2014532869/TestClientFallsBackToClosures1150879492/001/store/yh0i6mxnk5b9vr1x1kz4ns7qvngpb6nd-shared-dep2211 CA: text:sha256:16szz3s266prpsfj4ga7givpy980bwqjdpbi3k4i1dynm525qi602212 client_pushes_test.go:112: Retrieved narinfo from S3:2213 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientFallsBackToClosures1150879492/001/store/00qkfgl8s2h9l7mxn4vg9pawrdi74y1s-b2214 URL: nar/0aa2gp6ygksgyjqlglkywmkncknla1jyn6r9bxpilr4d5z0hsl9x.nar.zst2215 Compression: zstd2216 NarHash: sha256:0aa2gp6ygksgyjqlglkywmkncknla1jyn6r9bxpilr4d5z0hsl9x2217 NarSize: 2482218 References: /nix/var/nix/builds/nix-86274-2014532869/TestClientFallsBackToClosures1150879492/001/store/yh0i6mxnk5b9vr1x1kz4ns7qvngpb6nd-shared-dep2219 CA: text:sha256:16szz3s266prpsfj4ga7givpy980bwqjdpbi3k4i1dynm525qi6022202026-10-01 08:27:09.144 UTC [86644] ERROR: relation "goose_db_version" does not exist at character 3622212026-10-01 08:27:09.144 UTC [86644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2222--- PASS: TestClientFallsBackToClosures (3.91s)2223=== CONT TestClientErrorHandling2224=== RUN TestClientErrorHandling/InvalidStorePath2225=== PAUSE TestClientErrorHandling/InvalidStorePath2226=== RUN TestClientErrorHandling/InvalidAuthToken2227=== PAUSE TestClientErrorHandling/InvalidAuthToken2228=== RUN TestClientErrorHandling/ServerNotAvailable2229=== PAUSE TestClientErrorHandling/ServerNotAvailable2230=== CONT TestClientCADerivations22312026/10/01 08:27:09 INFO Received push request method=POST path=/api/pushes2232=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2233=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2234=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2235=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2236=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2237=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2238=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2239=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2240=== CONT TestReadProxyInvalidPath22412026/10/01 08:27:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)22422026/10/01 08:27:09 INFO Uploading qr1af52y8pn0w1avlw97bn03bb8xvzmc-a (248B)22432026/10/01 08:27:09 INFO Uploading hi7phwhj9xi7qj1fakdi04hnayrvlabz-shared-dep (136B)22442026/10/01 08:27:09 WARN Failed to register uploaded object key=nar/0hl5spxkr18hc0p6h9sa9h6d7fgcvmv01z0mk140sp5shdl5zi73.nar.zst error="server returned 404: 404 page not found\n"22452026/10/01 08:27:09 WARN Failed to register uploaded object key=qr1af52y8pn0w1avlw97bn03bb8xvzmc.ls error="server returned 404: 404 page not found\n"22462026/10/01 08:27:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22472026/10/01 08:27:09 WARN Failed to register uploaded object key=hi7phwhj9xi7qj1fakdi04hnayrvlabz.ls error="server returned 404: 404 page not found\n"22482026/10/01 08:27:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22492026/10/01 08:27:09 WARN Failed to register uploaded object key=hd9km24ygyfjwyib3nqyjx4c6prpydl1.ls error="server returned 404: 404 page not found\n"22502026/10/01 08:27:09 INFO Signed narinfos id=1 count=322512026/10/01 08:27:09 INFO Uploading 3 narinfos22522026/10/01 08:27:09 WARN Failed to register uploaded object key=hi7phwhj9xi7qj1fakdi04hnayrvlabz.narinfo error="server returned 404: 404 page not found\n"22532026/10/01 08:27:09 WARN Failed to register uploaded object key=qr1af52y8pn0w1avlw97bn03bb8xvzmc.narinfo error="server returned 404: 404 page not found\n"22542026/10/01 08:27:09 INFO Received complete push request method=POST path=/api/pushes/1/complete22552026/10/01 08:27:09 WARN Failed to register uploaded object key=hd9km24ygyfjwyib3nqyjx4c6prpydl1.narinfo error="server returned 404: 404 page not found\n"22562026/10/01 08:27:09 INFO Upload complete. (189ms)2257=== NAME TestClientPushesUseOnePush2258 client_pushes_test.go:97: Retrieved narinfo from S3:2259 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientPushesUseOnePush496383267/001/store/hi7phwhj9xi7qj1fakdi04hnayrvlabz-shared-dep2260 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2261 Compression: zstd2262 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822263 NarSize: 1362264 References: 2265 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22662026-10-01 08:27:09.322 UTC [86653] ERROR: relation "goose_db_version" does not exist at character 3622672026-10-01 08:27:09.322 UTC [86653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2268 client_pushes_test.go:97: Retrieved narinfo from S3:2269 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientPushesUseOnePush496383267/001/store/qr1af52y8pn0w1avlw97bn03bb8xvzmc-a2270 URL: nar/0hl5spxkr18hc0p6h9sa9h6d7fgcvmv01z0mk140sp5shdl5zi73.nar.zst2271 Compression: zstd2272 NarHash: sha256:0hl5spxkr18hc0p6h9sa9h6d7fgcvmv01z0mk140sp5shdl5zi732273 NarSize: 2482274 References: /nix/var/nix/builds/nix-86274-2014532869/TestClientPushesUseOnePush496383267/001/store/hi7phwhj9xi7qj1fakdi04hnayrvlabz-shared-dep2275 CA: text:sha256:0h1s0ganhvlj1arc43kmmrm5b1r0fy0vwvbqsk8y6s2czcp8dnib2276 client_pushes_test.go:97: Retrieved narinfo from S3:2277 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientPushesUseOnePush496383267/001/store/hd9km24ygyfjwyib3nqyjx4c6prpydl1-b2278 URL: nar/0hl5spxkr18hc0p6h9sa9h6d7fgcvmv01z0mk140sp5shdl5zi73.nar.zst2279 Compression: zstd2280 NarHash: sha256:0hl5spxkr18hc0p6h9sa9h6d7fgcvmv01z0mk140sp5shdl5zi732281 NarSize: 2482282 References: /nix/var/nix/builds/nix-86274-2014532869/TestClientPushesUseOnePush496383267/001/store/hi7phwhj9xi7qj1fakdi04hnayrvlabz-shared-dep2283 CA: text:sha256:0h1s0ganhvlj1arc43kmmrm5b1r0fy0vwvbqsk8y6s2czcp8dnib2284--- PASS: TestClientPushesUseOnePush (3.72s)2285=== CONT TestService_ReadAuthMiddleware22862026/10/01 08:27:09 OK 20241026095416_initial_model.sql (197.29ms)22872026/10/01 08:27:09 OK 20251210153512_drop_unused_gin_index.sql (18.7ms)22882026/10/01 08:27:09 OK 20251218171726_add_pins.sql (26.49ms)22892026/10/01 08:27:09 OK 20260628120000_add_object_size_and_stats.sql (40.08ms)22902026/10/01 08:27:09 OK 20241026095416_initial_model.sql (180.34ms)22912026/10/01 08:27:09 OK 20260905000000_add_claims.sql (57.66ms)22922026/10/01 08:27:09 OK 20251210153512_drop_unused_gin_index.sql (11.7ms)22932026/10/01 08:27:09 OK 20260920000000_drop_claims.sql (16.64ms)22942026-10-01 08:27:09.585 UTC [86658] ERROR: relation "goose_db_version" does not exist at character 3622952026-10-01 08:27:09.585 UTC [86658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22962026-10-01 08:27:09.585 UTC [86657] ERROR: relation "goose_db_version" does not exist at character 3622972026-10-01 08:27:09.585 UTC [86657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22982026/10/01 08:27:09 OK 20251218171726_add_pins.sql (6.74ms)22992026/10/01 08:27:09 OK 20260923120000_add_pushes.sql (2.13ms)23002026/10/01 08:27:09 goose: successfully migrated database to version: 2026092312000023012026/10/01 08:27:09 OK 1_commit_pending_closure.sql (1.59ms)23022026/10/01 08:27:09 OK 2_object_stats_trigger.sql (307.71µs)23032026/10/01 08:27:09 OK 3_commit_push.sql (184.75µs)23042026/10/01 08:27:09 goose: up to current file version: 323052026/10/01 08:27:09 OK 20260628120000_add_object_size_and_stats.sql (30.34ms)23062026/10/01 08:27:09 OK 20260905000000_add_claims.sql (37.84ms)23072026/10/01 08:27:09 OK 20260920000000_drop_claims.sql (16.19ms)2308=== NAME TestClientIntegration2309 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-86274-2014532869/TestClientIntegration258040146/002/store/1f7x591l55nlw223gfwgh0hsv15rb82i-test-file.txt23102026/10/01 08:27:09 OK 20260923120000_add_pushes.sql (9.7ms)23112026/10/01 08:27:09 goose: successfully migrated database to version: 2026092312000023122026/10/01 08:27:09 OK 1_commit_pending_closure.sql (1.28ms)23132026/10/01 08:27:09 OK 2_object_stats_trigger.sql (271.04µs)23142026/10/01 08:27:09 OK 3_commit_push.sql (235.83µs)23152026/10/01 08:27:09 goose: up to current file version: 323162026/10/01 08:27:09 OK 20241026095416_initial_model.sql (68.25ms)23172026/10/01 08:27:09 OK 20251210153512_drop_unused_gin_index.sql (9.19ms)23182026/10/01 08:27:09 OK 20241026095416_initial_model.sql (65.03ms)23192026/10/01 08:27:09 OK 20251210153512_drop_unused_gin_index.sql (7.26ms)23202026/10/01 08:27:09 OK 20251218171726_add_pins.sql (9.43ms)23212026/10/01 08:27:09 OK 20251218171726_add_pins.sql (6.96ms)23222026/10/01 08:27:09 OK 20260628120000_add_object_size_and_stats.sql (12.03ms)23232026/10/01 08:27:09 OK 20260628120000_add_object_size_and_stats.sql (8.87ms)23242026/10/01 08:27:09 OK 20260905000000_add_claims.sql (20.8ms)23252026/10/01 08:27:09 OK 20260905000000_add_claims.sql (31.62ms)23262026/10/01 08:27:09 OK 20260920000000_drop_claims.sql (13.64ms)23272026/10/01 08:27:09 INFO Received push request method=POST path=/api/pushes23282026/10/01 08:27:09 OK 20260923120000_add_pushes.sql (7.65ms)23292026/10/01 08:27:09 goose: successfully migrated database to version: 2026092312000023302026/10/01 08:27:09 OK 20260920000000_drop_claims.sql (8.84ms)23312026/10/01 08:27:09 OK 1_commit_pending_closure.sql (1.12ms)23322026/10/01 08:27:09 OK 2_object_stats_trigger.sql (259.17µs)23332026/10/01 08:27:09 OK 3_commit_push.sql (184.79µs)23342026/10/01 08:27:09 goose: up to current file version: 323352026/10/01 08:27:09 OK 20260923120000_add_pushes.sql (13.27ms)23362026/10/01 08:27:09 goose: successfully migrated database to version: 2026092312000023372026/10/01 08:27:09 OK 1_commit_pending_closure.sql (924.75µs)23382026/10/01 08:27:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23392026/10/01 08:27:09 INFO Uploading 1f7x591l55nlw223gfwgh0hsv15rb82i-test-file.txt (152B)23402026/10/01 08:27:09 OK 2_object_stats_trigger.sql (245.71µs)23412026/10/01 08:27:09 OK 3_commit_push.sql (164.42µs)23422026/10/01 08:27:09 goose: up to current file version: 323432026/10/01 08:27:09 WARN Failed to register uploaded object key=1f7x591l55nlw223gfwgh0hsv15rb82i.ls error="server returned 404: 404 page not found\n"23442026/10/01 08:27:09 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"23452026/10/01 08:27:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23462026/10/01 08:27:09 INFO Signed narinfos id=1 count=123472026/10/01 08:27:09 INFO Uploading 1 narinfos23482026/10/01 08:27:09 INFO Received complete push request method=POST path=/api/pushes/1/complete23492026/10/01 08:27:09 WARN Failed to register uploaded object key=1f7x591l55nlw223gfwgh0hsv15rb82i.narinfo error="server returned 404: 404 page not found\n"23502026/10/01 08:27:09 INFO Upload complete. (118ms)23512026-10-01 08:27:09.837 UTC [86664] ERROR: relation "goose_db_version" does not exist at character 3623522026-10-01 08:27:09.837 UTC [86664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23532026/10/01 08:27:09 INFO All 1 paths already cached2354 client_integration_test.go:312: Retrieved narinfo from S3:2355 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientIntegration258040146/002/store/1f7x591l55nlw223gfwgh0hsv15rb82i-test-file.txt2356 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2357 Compression: zstd2358 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12359 NarSize: 1522360 References: 2361 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12362 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2363 client_integration_test.go:313: Decompressed .ls content (64 bytes):2364 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2365 client_integration_test.go:316: Testing garbage collection...23662026/10/01 08:27:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures23672026/10/01 08:27:09 INFO Garbage collection started23682026/10/01 08:27:09 INFO Aborted multipart uploads count=023692026/10/01 08:27:09 WARN Force mode enabled - objects will be deleted immediately without grace period23702026/10/01 08:27:09 OK 20241026095416_initial_model.sql (70.98ms)23712026/10/01 08:27:09 OK 20251210153512_drop_unused_gin_index.sql (6.81ms)23722026/10/01 08:27:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=023732026/10/01 08:27:09 OK 20251218171726_add_pins.sql (18.79ms)2374--- PASS: TestService_ReadScope_PublicByDefault (3.19s)2375=== CONT TestService_AuthMiddleware_MTLSBoundSubjects23762026/10/01 08:27:09 INFO Vacuumed table table=pending_closures23772026/10/01 08:27:09 INFO Vacuumed table table=pending_objects23782026/10/01 08:27:10 INFO Vacuumed table table=multipart_uploads23792026/10/01 08:27:10 OK 20260628120000_add_object_size_and_stats.sql (33.09ms)23802026/10/01 08:27:10 INFO Vacuumed table table=closures23812026/10/01 08:27:10 OK 20260905000000_add_claims.sql (53.43ms)23822026/10/01 08:27:10 INFO Vacuumed table table=objects23832026/10/01 08:27:10 OK 20260920000000_drop_claims.sql (10.36ms)2384=== NAME TestClientWithDependencies2385 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-86274-2014532869/TestClientWithDependencies4128086015/001/store/di3q4h6lfrmrjrn12jcjfwmsznikzgrd-test-script23862026/10/01 08:27:10 OK 20260923120000_add_pushes.sql (2.1ms)23872026/10/01 08:27:10 goose: successfully migrated database to version: 2026092312000023882026/10/01 08:27:10 OK 1_commit_pending_closure.sql (942.92µs)23892026/10/01 08:27:10 OK 2_object_stats_trigger.sql (227.92µs)23902026/10/01 08:27:10 OK 3_commit_push.sql (204.54µs)23912026/10/01 08:27:10 goose: up to current file version: 32392 client_integration_test.go:615: Found 1 dependencies (including self)23932026/10/01 08:27:10 INFO Received push request method=POST path=/api/pushes23942026/10/01 08:27:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23952026/10/01 08:27:10 INFO Uploading di3q4h6lfrmrjrn12jcjfwmsznikzgrd-test-script (136B)23962026/10/01 08:27:10 WARN Failed to register uploaded object key=di3q4h6lfrmrjrn12jcjfwmsznikzgrd.ls error="server returned 404: 404 page not found\n"23972026/10/01 08:27:10 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"23982026/10/01 08:27:10 WARN Failed to register uploaded object key=log/a45lm1kwlqcz4v3zv27s0bcz8lyny5hx-test-script.drv error="server returned 404: 404 page not found\n"23992026/10/01 08:27:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24002026/10/01 08:27:10 INFO Signed narinfos id=1 count=124012026/10/01 08:27:10 INFO Uploading 1 narinfos24022026/10/01 08:27:10 INFO Received complete push request method=POST path=/api/pushes/1/complete24032026/10/01 08:27:10 WARN Failed to register uploaded object key=di3q4h6lfrmrjrn12jcjfwmsznikzgrd.narinfo error="server returned 404: 404 page not found\n"24042026/10/01 08:27:10 INFO Upload complete. (158ms)2405 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-86274-2014532869/TestClientWithDependencies4128086015/001/store) requires matching store prefix2406=== NAME TestClientMultipleUploads2407 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-86274-2014532869/TestClientMultipleUploads911546173/001/store/72fj8x1gp806a4mi3m6n87pxsdc0ackz-test-file-0.txt2408--- PASS: TestClientWithDependencies (3.57s)2409=== CONT TestClientSharedPathCommittedMidPush24102026-10-01 08:27:10.400 UTC [86685] ERROR: relation "goose_db_version" does not exist at character 3624112026-10-01 08:27:10.400 UTC [86685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2412=== RUN TestService_RequireScope_OIDC/builder_may_write2413=== PAUSE TestService_RequireScope_OIDC/builder_may_write2414=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2415=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2416=== RUN TestService_RequireScope_OIDC/ops_may_admin2417=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2418=== RUN TestService_RequireScope_OIDC/ops_may_not_write2419=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2420=== RUN TestService_RequireScope_OIDC/reader_may_not_write2421=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2422=== RUN TestService_RequireScope_OIDC/static_token_may_admin2423=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2424=== RUN TestService_RequireScope_OIDC/static_token_may_write2425=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2426=== RUN TestService_RequireScope_OIDC/reader_may_read2427=== PAUSE TestService_RequireScope_OIDC/reader_may_read2428=== RUN TestService_RequireScope_OIDC/writer_implies_read2429=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2430=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2431=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2432=== CONT TestParseSingleRange/end_clamped_to_size2433=== CONT TestParseSingleRange/none2434=== CONT TestParseSingleRange/open-ended2435=== CONT TestParseSingleRange/closed2436=== CONT TestParseSingleRange/malformed_end_before_start2437=== CONT TestParseSingleRange/malformed_both_empty2438=== CONT TestParseSingleRange/malformed_no_dash2439=== CONT TestParseSingleRange/multi-range_ignored2440=== CONT TestParseSingleRange/unknown_unit2441=== CONT TestParseSingleRange/start_past_EOF2442=== CONT TestParseSingleRange/suffix_exceeds_size2443=== CONT TestParseSingleRange/single_byte2444=== CONT TestParseSingleRange/suffix2445=== CONT TestParseSingleRange/start_far_past_EOF2446--- PASS: TestParseSingleRange (0.01s)2447 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2448 --- PASS: TestParseSingleRange/none (0.00s)2449 --- PASS: TestParseSingleRange/open-ended (0.00s)2450 --- PASS: TestParseSingleRange/closed (0.00s)2451 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2452 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2453 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2454 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2455 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2456 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2457 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2458 --- PASS: TestParseSingleRange/single_byte (0.00s)2459 --- PASS: TestParseSingleRange/suffix (0.00s)2460 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2461=== CONT TestIsValidCachePath/narinfo2462=== CONT TestIsValidCachePath/short_hash2463=== CONT TestIsValidCachePath/wrong_extension2464=== CONT TestIsValidCachePath/leading_slash2465=== CONT TestIsValidCachePath/empty2466=== CONT TestIsValidCachePath/random_path2467=== CONT TestIsValidCachePath/invalid_char_u2468=== CONT TestIsValidCachePath/invalid_char_e2469=== CONT TestIsValidCachePath/traversal_in_middle2470=== CONT TestIsValidCachePath/traversal_parent2471=== CONT TestIsValidCachePath/index.html2472=== CONT TestIsValidCachePath/nix-cache-info2473=== CONT TestIsValidCachePath/realisation2474=== CONT TestIsValidCachePath/log2475=== CONT TestIsValidCachePath/ls2476=== CONT TestIsValidCachePath/nar_uncompressed2477=== CONT TestIsValidCachePath/nar_bz22478=== CONT TestIsValidCachePath/nar_xz2479=== CONT TestIsValidCachePath/nar_zst2480=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2481--- PASS: TestIsValidCachePath (0.01s)2482 --- PASS: TestIsValidCachePath/narinfo (0.00s)2483 --- PASS: TestIsValidCachePath/short_hash (0.00s)2484 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2485 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2486 --- PASS: TestIsValidCachePath/empty (0.00s)2487 --- PASS: TestIsValidCachePath/random_path (0.00s)2488 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2489 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2490 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2491 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2492 --- PASS: TestIsValidCachePath/index.html (0.00s)2493 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2494 --- PASS: TestIsValidCachePath/realisation (0.00s)2495 --- PASS: TestIsValidCachePath/log (0.00s)2496 --- PASS: TestIsValidCachePath/ls (0.00s)2497 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2498 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2499 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2500 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2501 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2502=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure25032026/10/01 08:27:10 INFO Received uploads request method=POST path=/2504=== NAME TestClientMultipleUploads2505 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-86274-2014532869/TestClientMultipleUploads911546173/001/store/2dab35pw8ln1mymg9cxhz4vri5g5zxwg-test-file-1.txt25062026-10-01 08:27:10.487 UTC [86691] ERROR: relation "goose_db_version" does not exist at character 3625072026-10-01 08:27:10.487 UTC [86691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25082026-10-01 08:27:10.507 UTC [86693] ERROR: relation "goose_db_version" does not exist at character 3625092026-10-01 08:27:10.507 UTC [86693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25102026/10/01 08:27:10 OK 20241026095416_initial_model.sql (65.51ms)2511 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-86274-2014532869/TestClientMultipleUploads911546173/001/store/fywvmpnd09s1z21nljrpxssyz0nfc5jv-test-file-2.txt25122026/10/01 08:27:10 OK 20251210153512_drop_unused_gin_index.sql (6.29ms)25132026/10/01 08:27:10 OK 20251218171726_add_pins.sql (8.77ms)25142026/10/01 08:27:10 OK 20260628120000_add_object_size_and_stats.sql (11.64ms)25152026-10-01 08:27:10.545 UTC [86695] ERROR: relation "goose_db_version" does not exist at character 3625162026-10-01 08:27:10.545 UTC [86695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25172026/10/01 08:27:10 OK 20260905000000_add_claims.sql (22.61ms)25182026/10/01 08:27:10 OK 20260920000000_drop_claims.sql (11.34ms)25192026/10/01 08:27:10 OK 20260923120000_add_pushes.sql (9.61ms)25202026/10/01 08:27:10 goose: successfully migrated database to version: 2026092312000025212026/10/01 08:27:10 OK 20241026095416_initial_model.sql (62.68ms)25222026/10/01 08:27:10 OK 1_commit_pending_closure.sql (948.67µs)25232026/10/01 08:27:10 OK 2_object_stats_trigger.sql (200.54µs)25242026/10/01 08:27:10 OK 3_commit_push.sql (178.33µs)25252026/10/01 08:27:10 goose: up to current file version: 325262026/10/01 08:27:10 OK 20251210153512_drop_unused_gin_index.sql (6ms)25272026/10/01 08:27:10 OK 20241026095416_initial_model.sql (60.99ms)25282026/10/01 08:27:10 OK 20251210153512_drop_unused_gin_index.sql (7.07ms)25292026/10/01 08:27:10 INFO Received push request method=POST path=/api/pushes25302026/10/01 08:27:10 OK 20251218171726_add_pins.sql (13.62ms)2531--- PASS: TestReadProxyConditionalGet (2.57s)2532=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts25332026/10/01 08:27:10 INFO Received request for more parts method=POST path=/25342026/10/01 08:27:10 OK 20251218171726_add_pins.sql (25.79ms)25352026/10/01 08:27:10 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)25362026/10/01 08:27:10 INFO Uploading fywvmpnd09s1z21nljrpxssyz0nfc5jv-test-file-2.txt (160B)25372026/10/01 08:27:10 INFO Uploading 2dab35pw8ln1mymg9cxhz4vri5g5zxwg-test-file-1.txt (160B)25382026/10/01 08:27:10 INFO Uploading 72fj8x1gp806a4mi3m6n87pxsdc0ackz-test-file-0.txt (160B)2539=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25402026/10/01 08:27:10 INFO Received complete multipart upload request method=POST path=/25412026/10/01 08:27:10 OK 20260628120000_add_object_size_and_stats.sql (25.59ms)25422026/10/01 08:27:10 WARN Failed to register uploaded object key=72fj8x1gp806a4mi3m6n87pxsdc0ackz.ls error="server returned 404: 404 page not found\n"25432026/10/01 08:27:10 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"25442026/10/01 08:27:10 WARN Failed to register uploaded object key=2dab35pw8ln1mymg9cxhz4vri5g5zxwg.ls error="server returned 404: 404 page not found\n"25452026/10/01 08:27:10 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"25462026/10/01 08:27:10 WARN Failed to register uploaded object key=fywvmpnd09s1z21nljrpxssyz0nfc5jv.ls error="server returned 404: 404 page not found\n"25472026/10/01 08:27:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25482026/10/01 08:27:10 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"25492026/10/01 08:27:10 INFO Signed narinfos id=1 count=325502026/10/01 08:27:10 INFO Uploading 3 narinfos25512026/10/01 08:27:10 OK 20260628120000_add_object_size_and_stats.sql (20.29ms)2552=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info25532026/10/01 08:27:10 INFO Received uploads request method=POST path=/2554=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key25552026/10/01 08:27:10 INFO Received complete multipart upload request method=POST path=/2556=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key25572026/10/01 08:27:10 INFO Received request for more parts method=POST path=/2558=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal25592026/10/01 08:27:10 INFO Received uploads request method=POST path=/2560--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2561 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2562 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2563 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2564 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2565=== CONT TestIsValidUploadKey/narinfo2566=== CONT TestIsValidUploadKey/realisation_plus_in_output2567=== CONT TestIsValidUploadKey/unknown_type2568=== CONT TestIsValidUploadKey/empty_key2569=== CONT TestIsValidUploadKey/absolute2570=== CONT TestIsValidUploadKey/traversal_nar2571=== CONT TestIsValidUploadKey/traversal2572=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2573=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2574=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2575=== CONT TestIsValidUploadKey/index.html2576=== CONT TestIsValidUploadKey/nix-cache-info2577=== CONT TestIsValidUploadKey/build_log_home-manager_file2578=== CONT TestIsValidUploadKey/realisation2579=== CONT TestIsValidUploadKey/build_log_equals2580=== CONT TestIsValidUploadKey/build_log_question_mark2581=== CONT TestIsValidUploadKey/build_log_plus_in_name2582=== CONT TestIsValidUploadKey/nar_plain2583=== CONT TestIsValidUploadKey/build_log2584=== CONT TestIsValidUploadKey/listing2585=== CONT TestIsValidUploadKey/nar_xz2586=== CONT TestIsValidUploadKey/nar_zst2587--- PASS: TestIsValidUploadKey (0.00s)2588 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2589 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2590 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2591 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2592 --- PASS: TestIsValidUploadKey/absolute (0.00s)2593 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2594 --- PASS: TestIsValidUploadKey/traversal (0.00s)2595 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2596 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2597 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2598 --- PASS: TestIsValidUploadKey/index.html (0.00s)2599 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2600 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2601 --- PASS: TestIsValidUploadKey/realisation (0.00s)2602 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2603 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2604 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2605 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2606 --- PASS: TestIsValidUploadKey/build_log (0.00s)2607 --- PASS: TestIsValidUploadKey/listing (0.00s)2608 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2609 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2610=== CONT TestProxyWriteTimeout/narinfo2611=== CONT TestProxyWriteTimeout/10_GiB_nar2612=== CONT TestProxyWriteTimeout/unknown_size2613=== CONT TestProxyWriteTimeout/1_GiB_nar2614--- PASS: TestProxyWriteTimeout (0.00s)2615 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2616 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2617 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2618 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2619=== CONT TestPush_RejectsBadRequests/root_not_in_objects26202026/10/01 08:27:10 INFO Received push request method=POST path=/api/pushes2621=== CONT TestPush_RejectsBadRequests/bad_root26222026/10/01 08:27:10 INFO Received push request method=POST path=/api/pushes2623=== CONT TestPush_RejectsBadRequests/no_objects26242026/10/01 08:27:10 INFO Received push request method=POST path=/api/pushes2625=== CONT TestPush_RejectsBadRequests/no_roots26262026/10/01 08:27:10 INFO Received push request method=POST path=/api/pushes2627=== CONT TestServerTLSConfig/no_client_CA2628=== CONT TestServerTLSConfig/not_a_PEM_file2629--- PASS: TestPush_RejectsBadRequests (2.42s)2630 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2631 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2632 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2633 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2634=== CONT TestServerTLSConfig/missing_CA_file2635--- PASS: TestServerTLSConfig (0.00s)2636 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2637 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2638 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2639=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows26402026/10/01 08:27:10 OK 20260905000000_add_claims.sql (41.75ms)26412026/10/01 08:27:10 INFO Received complete push request method=POST path=/api/pushes/1/complete26422026/10/01 08:27:10 WARN Failed to register uploaded object key=72fj8x1gp806a4mi3m6n87pxsdc0ackz.narinfo error="server returned 404: 404 page not found\n"26432026/10/01 08:27:10 WARN Failed to register uploaded object key=2dab35pw8ln1mymg9cxhz4vri5g5zxwg.narinfo error="server returned 404: 404 page not found\n"26442026/10/01 08:27:10 WARN Failed to register uploaded object key=fywvmpnd09s1z21nljrpxssyz0nfc5jv.narinfo error="server returned 404: 404 page not found\n"26452026/10/01 08:27:10 OK 20260905000000_add_claims.sql (33.85ms)26462026/10/01 08:27:10 INFO Upload complete. (131ms)2647=== NAME TestClientMultipleUploads2648 client_integration_test.go:369: Uploaded 3 paths in 170.126291ms2649--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2650 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2651 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2652 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2653=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check26542026/10/01 08:27:10 OK 20260920000000_drop_claims.sql (26.6ms)26552026/10/01 08:27:10 OK 20260920000000_drop_claims.sql (28.23ms)26562026/10/01 08:27:10 OK 20241026095416_initial_model.sql (126.72ms)26572026/10/01 08:27:10 OK 20251210153512_drop_unused_gin_index.sql (14.1ms)26582026/10/01 08:27:10 OK 20260923120000_add_pushes.sql (26.08ms)26592026/10/01 08:27:10 goose: successfully migrated database to version: 2026092312000026602026/10/01 08:27:10 OK 20260923120000_add_pushes.sql (19.73ms)26612026/10/01 08:27:10 goose: successfully migrated database to version: 2026092312000026622026/10/01 08:27:10 OK 1_commit_pending_closure.sql (1.19ms)26632026/10/01 08:27:10 OK 1_commit_pending_closure.sql (1.26ms)26642026/10/01 08:27:10 OK 2_object_stats_trigger.sql (210.08µs)26652026/10/01 08:27:10 OK 2_object_stats_trigger.sql (226.71µs)26662026/10/01 08:27:10 OK 3_commit_push.sql (168.29µs)26672026/10/01 08:27:10 goose: up to current file version: 326682026/10/01 08:27:10 OK 3_commit_push.sql (176.75µs)26692026/10/01 08:27:10 goose: up to current file version: 326702026/10/01 08:27:10 OK 20251218171726_add_pins.sql (16.02ms)2671--- PASS: TestClientMultipleUploads (3.26s)2672=== CONT TestResolveDBConnectionString/flag_wins2673=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2674=== CONT TestResolveDBConnectionString/nothing_configured2675=== CONT TestResolveDBConnectionString/missing_file_is_an_error2676=== CONT TestResolveDBConnectionString/file_when_flag_empty2677=== CONT TestCacheConfigHandler/full_config,_no_issuer2678=== CONT TestCacheConfigHandler/no_signing_keys2679=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2680=== CONT TestCacheConfigHandler/no_cache_url_configured2681--- PASS: TestCacheConfigHandler (0.00s)2682 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2683 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2684 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2685 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2686=== CONT TestClientErrorHandling/InvalidStorePath2687--- PASS: TestResolveDBConnectionString (0.01s)2688 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2689 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2690 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2691 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2692 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)26932026/10/01 08:27:10 OK 20260628120000_add_object_size_and_stats.sql (31.19ms)26942026/10/01 08:27:10 OK 20260905000000_add_claims.sql (26.18ms)26952026/10/01 08:27:10 OK 20260920000000_drop_claims.sql (21.29ms)2696--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.91s)2697=== CONT TestClientErrorHandling/ServerNotAvailable26982026/10/01 08:27:10 OK 20260923120000_add_pushes.sql (8.07ms)26992026/10/01 08:27:10 goose: successfully migrated database to version: 2026092312000027002026/10/01 08:27:10 OK 1_commit_pending_closure.sql (1.26ms)27012026/10/01 08:27:10 OK 2_object_stats_trigger.sql (245.96µs)27022026/10/01 08:27:10 OK 3_commit_push.sql (199.08µs)27032026/10/01 08:27:10 goose: up to current file version: 327042026-10-01 08:27:10.959 UTC [86708] ERROR: relation "goose_db_version" does not exist at character 3627052026-10-01 08:27:10.959 UTC [86708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27062026/10/01 08:27:10 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27072026/10/01 08:27:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.02836ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27082026/10/01 08:27:11 OK 20241026095416_initial_model.sql (118.93ms)27092026/10/01 08:27:11 OK 20251210153512_drop_unused_gin_index.sql (5.65ms)27102026/10/01 08:27:11 OK 20251218171726_add_pins.sql (7.07ms)27112026/10/01 08:27:11 OK 20260628120000_add_object_size_and_stats.sql (17.68ms)27122026/10/01 08:27:11 OK 20260905000000_add_claims.sql (25.7ms)2713--- PASS: TestReadProxyInvalidPath (2.00s)2714=== CONT TestClientErrorHandling/InvalidAuthToken27152026/10/01 08:27:11 OK 20260920000000_drop_claims.sql (9.92ms)27162026/10/01 08:27:11 OK 20260923120000_add_pushes.sql (14.04ms)27172026/10/01 08:27:11 goose: successfully migrated database to version: 2026092312000027182026/10/01 08:27:11 OK 1_commit_pending_closure.sql (865.58µs)27192026/10/01 08:27:11 OK 2_object_stats_trigger.sql (215.58µs)27202026/10/01 08:27:11 OK 3_commit_push.sql (190.75µs)27212026/10/01 08:27:11 goose: up to current file version: 327222026/10/01 08:27:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.21257ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27232026-10-01 08:27:11.297 UTC [86717] ERROR: relation "goose_db_version" does not exist at character 3627242026-10-01 08:27:11.297 UTC [86717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2725=== NAME TestClientCADerivations2726 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-86274-2014532869/TestClientCADerivations2187670469/001/store/lx8gjr9lygmv2686dpz2c0g03lhfqsvh-ca-test2727 client_ca_test.go:139: Found 1 dependencies (including self)2728--- PASS: TestService_ReadAuthMiddleware (1.95s)2729=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2730=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected27312026/10/01 08:27:11 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]2732=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2733=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27342026/10/01 08:27:11 WARN Authentication failed token_preview=eyJhbGciOi...FLJGCsffbw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2735=== CONT TestService_RequireScope_OIDC/builder_may_write2736=== CONT TestService_RequireScope_OIDC/static_token_may_admin2737=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2738=== CONT TestService_RequireScope_OIDC/writer_implies_read2739=== CONT TestService_RequireScope_OIDC/reader_may_read2740=== CONT TestService_RequireScope_OIDC/static_token_may_write2741=== CONT TestService_RequireScope_OIDC/ops_may_not_write2742=== CONT TestService_RequireScope_OIDC/reader_may_not_write2743=== CONT TestService_RequireScope_OIDC/ops_may_admin2744=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2745--- PASS: TestService_RequireScope_OIDC (3.06s)2746 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2747 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2748 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2749 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2750 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2751 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2752 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2753 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2754 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2755 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2756--- PASS: TestService_AuthMiddleware_OIDC (3.36s)2757 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2758 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2759 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2760 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)27612026/10/01 08:27:11 OK 20241026095416_initial_model.sql (84ms)27622026/10/01 08:27:11 OK 20251210153512_drop_unused_gin_index.sql (7.45ms)27632026/10/01 08:27:11 OK 20251218171726_add_pins.sql (13.74ms)27642026/10/01 08:27:11 OK 20260628120000_add_object_size_and_stats.sql (8.12ms)27652026/10/01 08:27:11 OK 20260905000000_add_claims.sql (8.34ms)27662026/10/01 08:27:11 OK 20260920000000_drop_claims.sql (7.86ms)27672026/10/01 08:27:11 OK 20260923120000_add_pushes.sql (5.73ms)27682026/10/01 08:27:11 goose: successfully migrated database to version: 2026092312000027692026/10/01 08:27:11 OK 1_commit_pending_closure.sql (1.14ms)27702026/10/01 08:27:11 OK 2_object_stats_trigger.sql (230.88µs)27712026/10/01 08:27:11 OK 3_commit_push.sql (192.54µs)27722026/10/01 08:27:11 goose: up to current file version: 327732026/10/01 08:27:11 INFO Received push request method=POST path=/api/pushes27742026/10/01 08:27:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27752026/10/01 08:27:11 INFO Uploading lx8gjr9lygmv2686dpz2c0g03lhfqsvh-ca-test (144B)27762026/10/01 08:27:11 WARN Failed to register uploaded object key=lx8gjr9lygmv2686dpz2c0g03lhfqsvh.ls error="server returned 404: 404 page not found\n"27772026/10/01 08:27:11 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"27782026-10-01 08:27:11.516 UTC [86726] ERROR: relation "goose_db_version" does not exist at character 3627792026-10-01 08:27:11.516 UTC [86726] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27802026/10/01 08:27:11 WARN Failed to register uploaded object key=log/fyqzcwbvs95zw9xy2qk162pyzskazw13-ca-test.drv error="server returned 404: 404 page not found\n"27812026/10/01 08:27:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27822026/10/01 08:27:11 INFO Signed narinfos id=1 count=127832026/10/01 08:27:11 INFO Uploading 1 narinfos27842026/10/01 08:27:11 INFO Received complete push request method=POST path=/api/pushes/1/complete27852026/10/01 08:27:11 WARN Failed to register uploaded object key=lx8gjr9lygmv2686dpz2c0g03lhfqsvh.narinfo error="server returned 404: 404 page not found\n"27862026/10/01 08:27:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"27872026/10/01 08:27:11 WARN mTLS auth: bound subjects configured but subject DN unavailable27882026/10/01 08:27:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2789--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.58s)27902026-10-01 08:27:11.568 UTC [86727] ERROR: relation "goose_db_version" does not exist at character 3627912026-10-01 08:27:11.568 UTC [86727] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27922026/10/01 08:27:11 INFO Upload complete. (185ms)2793=== NAME TestClientCADerivations2794 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientCADerivations2187670469/001/store/lx8gjr9lygmv2686dpz2c0g03lhfqsvh-ca-test2795 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2796 Compression: zstd2797 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2798 NarSize: 1442799 References: 2800 Deriver: /nix/var/nix/builds/nix-86274-2014532869/TestClientCADerivations2187670469/001/store/fyqzcwbvs95zw9xy2qk162pyzskazw13-ca-test.drv2801 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2802 client_ca_test.go:185: Checking for realisation files in S3...2803 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2804 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2805 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket71?endpoint=http://localhost:59878®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-86274-2014532869/TestClientCADerivations2187670469/001/store'2806 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 128072026/10/01 08:27:11 OK 20241026095416_initial_model.sql (70.48ms)28082026/10/01 08:27:11 OK 20251210153512_drop_unused_gin_index.sql (5.9ms)2809--- PASS: TestClientCADerivations (2.50s)28102026-10-01 08:27:11.652 UTC [86730] ERROR: relation "goose_db_version" does not exist at character 3628112026-10-01 08:27:11.652 UTC [86730] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28122026/10/01 08:27:11 OK 20241026095416_initial_model.sql (44.19ms)28132026/10/01 08:27:11 OK 20251218171726_add_pins.sql (7.64ms)28142026/10/01 08:27:11 OK 20251210153512_drop_unused_gin_index.sql (4.6ms)28152026/10/01 08:27:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=735.911203ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28162026/10/01 08:27:11 OK 20251218171726_add_pins.sql (5.64ms)28172026/10/01 08:27:11 OK 20260628120000_add_object_size_and_stats.sql (10.02ms)28182026/10/01 08:27:11 OK 20260628120000_add_object_size_and_stats.sql (7.18ms)28192026/10/01 08:27:11 OK 20260905000000_add_claims.sql (7.26ms)28202026/10/01 08:27:11 OK 20260920000000_drop_claims.sql (10.87ms)28212026/10/01 08:27:11 OK 20260923120000_add_pushes.sql (929.54µs)28222026/10/01 08:27:11 goose: successfully migrated database to version: 2026092312000028232026/10/01 08:27:11 OK 1_commit_pending_closure.sql (955µs)28242026/10/01 08:27:11 OK 2_object_stats_trigger.sql (228.08µs)28252026/10/01 08:27:11 OK 3_commit_push.sql (194.79µs)28262026/10/01 08:27:11 goose: up to current file version: 328272026/10/01 08:27:11 OK 20260905000000_add_claims.sql (19.63ms)28282026/10/01 08:27:11 OK 20260920000000_drop_claims.sql (8.84ms)28292026/10/01 08:27:11 OK 20260923120000_add_pushes.sql (968.67µs)28302026/10/01 08:27:11 goose: successfully migrated database to version: 2026092312000028312026/10/01 08:27:11 OK 1_commit_pending_closure.sql (899.25µs)28322026/10/01 08:27:11 OK 2_object_stats_trigger.sql (238.71µs)28332026/10/01 08:27:11 OK 3_commit_push.sql (182.5µs)28342026/10/01 08:27:11 goose: up to current file version: 328352026/10/01 08:27:11 OK 20241026095416_initial_model.sql (56.94ms)28362026/10/01 08:27:11 OK 20251210153512_drop_unused_gin_index.sql (600.54µs)28372026/10/01 08:27:11 OK 20251218171726_add_pins.sql (12.64ms)28382026/10/01 08:27:11 OK 20260628120000_add_object_size_and_stats.sql (21.3ms)28392026/10/01 08:27:11 OK 20260905000000_add_claims.sql (10.4ms)28402026/10/01 08:27:11 OK 20260920000000_drop_claims.sql (16.48ms)28412026/10/01 08:27:11 OK 20260923120000_add_pushes.sql (5.2ms)28422026/10/01 08:27:11 goose: successfully migrated database to version: 2026092312000028432026/10/01 08:27:11 OK 1_commit_pending_closure.sql (893.58µs)28442026/10/01 08:27:11 OK 2_object_stats_trigger.sql (231.29µs)28452026/10/01 08:27:11 OK 3_commit_push.sql (186.13µs)28462026/10/01 08:27:11 goose: up to current file version: 328472026-10-01 08:27:11.872 UTC [86734] ERROR: relation "goose_db_version" does not exist at character 3628482026-10-01 08:27:11.872 UTC [86734] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28492026/10/01 08:27:11 INFO Received uploads request method=POST path=/api/pending_closures28502026/10/01 08:27:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02851=== NAME TestClientIntegration2852 client_integration_test.go:323: Objects in database after GC:2853 client_integration_test.go:323: Successfully deleted all objects with GC --force28542026/10/01 08:27:11 INFO Aborted multipart uploads count=028552026/10/01 08:27:11 WARN Force mode enabled - objects will be deleted immediately without grace period28562026/10/01 08:27:11 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=028572026/10/01 08:27:11 INFO Vacuumed table table=pending_closures28582026/10/01 08:27:11 INFO Vacuumed table table=pending_objects28592026/10/01 08:27:11 INFO Vacuumed table table=multipart_uploads28602026/10/01 08:27:11 INFO Vacuumed table table=closures28612026/10/01 08:27:11 OK 20241026095416_initial_model.sql (53.23ms)28622026/10/01 08:27:11 INFO Vacuumed table table=objects28632026/10/01 08:27:11 OK 20251210153512_drop_unused_gin_index.sql (11.94ms)28642026/10/01 08:27:11 INFO Received push request method=POST path=/api/pushes2865--- PASS: TestClientIntegration (5.83s)28662026/10/01 08:27:11 OK 20251218171726_add_pins.sql (22.61ms)28672026/10/01 08:27:11 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)28682026/10/01 08:27:11 INFO Uploading jihpzx3clk3mkvj8fqwzj159kb7aqgvy-top (256B)28692026/10/01 08:27:11 INFO Uploading 1sf52vn1g16pca4zji9znryfgpfrmi5n-shared-dep (136B)28702026/10/01 08:27:11 OK 20260628120000_add_object_size_and_stats.sql (18.26ms)28712026/10/01 08:27:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"28722026/10/01 08:27:11 WARN Failed to register uploaded object key=1sf52vn1g16pca4zji9znryfgpfrmi5n.ls error="server returned 404: 404 page not found\n"28732026/10/01 08:27:11 WARN Failed to register uploaded object key=nar/0sz88qpcgvd771lgshb22akdf9n0c1lm89ab1m8xfl4rxrhc5cz9.nar.zst error="server returned 404: 404 page not found\n"28742026/10/01 08:27:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28752026/10/01 08:27:11 WARN Failed to register uploaded object key=jihpzx3clk3mkvj8fqwzj159kb7aqgvy.ls error="server returned 404: 404 page not found\n"28762026/10/01 08:27:11 INFO Signed narinfos id=1 count=228772026/10/01 08:27:11 INFO Uploading 2 narinfos28782026/10/01 08:27:12 WARN Failed to register uploaded object key=jihpzx3clk3mkvj8fqwzj159kb7aqgvy.narinfo error="server returned 404: 404 page not found\n"28792026/10/01 08:27:12 INFO Received complete push request method=POST path=/api/pushes/1/complete28802026/10/01 08:27:12 WARN Failed to register uploaded object key=1sf52vn1g16pca4zji9znryfgpfrmi5n.narinfo error="server returned 404: 404 page not found\n"28812026/10/01 08:27:12 OK 20260905000000_add_claims.sql (31.56ms)28822026/10/01 08:27:12 INFO Upload complete. (109ms)2883=== NAME TestClientSharedPathCommittedMidPush2884 client_integration_test.go:680: Retrieved narinfo from S3:2885 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientSharedPathCommittedMidPush3441746180/001/store/1sf52vn1g16pca4zji9znryfgpfrmi5n-shared-dep2886 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2887 Compression: zstd2888 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822889 NarSize: 1362890 References: 2891 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2892 client_integration_test.go:680: Retrieved narinfo from S3:2893 StorePath: /nix/var/nix/builds/nix-86274-2014532869/TestClientSharedPathCommittedMidPush3441746180/001/store/jihpzx3clk3mkvj8fqwzj159kb7aqgvy-top2894 URL: nar/0sz88qpcgvd771lgshb22akdf9n0c1lm89ab1m8xfl4rxrhc5cz9.nar.zst2895 Compression: zstd2896 NarHash: sha256:0sz88qpcgvd771lgshb22akdf9n0c1lm89ab1m8xfl4rxrhc5cz92897 NarSize: 2562898 References: /nix/var/nix/builds/nix-86274-2014532869/TestClientSharedPathCommittedMidPush3441746180/001/store/1sf52vn1g16pca4zji9znryfgpfrmi5n-shared-dep2899 CA: text:sha256:0kc761gqbmisr24dddvy1lq5g4cdjh4i3r08m4k1yci4pisddkd529002026/10/01 08:27:12 OK 20260920000000_drop_claims.sql (14.77ms)29012026/10/01 08:27:12 OK 20260923120000_add_pushes.sql (14.36ms)29022026/10/01 08:27:12 goose: successfully migrated database to version: 2026092312000029032026/10/01 08:27:12 OK 1_commit_pending_closure.sql (1.19ms)29042026/10/01 08:27:12 OK 2_object_stats_trigger.sql (249.63µs)29052026/10/01 08:27:12 OK 3_commit_push.sql (210.75µs)29062026/10/01 08:27:12 goose: up to current file version: 32907--- PASS: TestClientSharedPathCommittedMidPush (1.69s)29082026/10/01 08:27:12 INFO Received uploads request method=POST path=/api/pending_closures29092026/10/01 08:27:12 INFO Aborted multipart uploads count=029102026/10/01 08:27:12 WARN Force mode enabled - objects will be deleted immediately without grace period29112026/10/01 08:27:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=029122026/10/01 08:27:12 INFO Vacuumed table table=pending_closures29132026/10/01 08:27:12 INFO Vacuumed table table=pending_objects29142026/10/01 08:27:12 INFO Vacuumed table table=multipart_uploads29152026/10/01 08:27:12 INFO Vacuumed table table=closures29162026/10/01 08:27:12 INFO Vacuumed table table=objects2917--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2918 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.27s)2919 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.54s)29202026/10/01 08:27:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.649483005s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29212026/10/01 08:27:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29222026/10/01 08:27:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29232026/10/01 08:27:14 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29242026/10/01 08:27:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.215327ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29252026/10/01 08:27:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=406.677112ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29262026/10/01 08:27:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=791.855018ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29272026/10/01 08:27:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.560765658s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29282026/10/01 08:27:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"29292026/10/01 08:27:17 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29302026/10/01 08:27:17 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.651137ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29312026/10/01 08:27:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.510112ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29322026/10/01 08:27:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.456445ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29332026/10/01 08:27:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.491721565s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29342026/10/01 08:27:20 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29352026/10/01 08:27:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.919178ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29362026/10/01 08:27:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.040646ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29372026/10/01 08:27:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=723.086554ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29382026/10/01 08:27:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.450909757s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2939--- PASS: TestClientErrorHandling (0.00s)2940 --- PASS: TestClientErrorHandling/InvalidStorePath (1.57s)2941 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.38s)2942 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.23s)2943PASS2944{"timestamp":"2026-10-01T08:27:23.049783Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59951","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(11)"}29452026-10-01 08:27:23.157 UTC [86329] LOG: received smart shutdown request29462026-10-01 08:27:23.157 UTC [86329] LOG: background worker "logical replication launcher" (PID 86339) exited with exit code 129472026-10-01 08:27:23.182 UTC [86334] LOG: shutting down29482026-10-01 08:27:23.182 UTC [86334] LOG: checkpoint starting: shutdown immediate29492026-10-01 08:27:24.385 UTC [86334] LOG: checkpoint complete: wrote 12616 buffers (77.0%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 22 recycled; write=0.692 s, sync=0.452 s, total=1.203 s; sync files=26626, longest=0.001 s, average=0.001 s; distance=368523 kB, estimate=368523 kB; lsn=0/17F6FC68, redo lsn=0/17F6FC6829502026-10-01 08:27:24.390 UTC [86329] LOG: database system is shut down2951Running OIDC tests...2952=== RUN TestAudienceForIssuer2953=== PAUSE TestAudienceForIssuer2954=== RUN TestGlobMatch2955=== PAUSE TestGlobMatch2956=== RUN TestValidateToken_ValidToken2957=== PAUSE TestValidateToken_ValidToken2958=== RUN TestValidateToken_WrongAudience2959=== PAUSE TestValidateToken_WrongAudience2960=== RUN TestValidateToken_Expired2961=== PAUSE TestValidateToken_Expired2962=== RUN TestValidateToken_BoundClaimsMismatch2963=== PAUSE TestValidateToken_BoundClaimsMismatch2964=== RUN TestValidateToken_BoundSubjectMismatch2965=== PAUSE TestValidateToken_BoundSubjectMismatch2966=== RUN TestValidateToken_MultipleProviders2967=== PAUSE TestValidateToken_MultipleProviders2968=== RUN TestValidateToken_NoMatchingProvider2969=== PAUSE TestValidateToken_NoMatchingProvider2970=== RUN TestValidateToken_KubernetesServiceAccount2971=== PAUSE TestValidateToken_KubernetesServiceAccount2972=== RUN TestNewValidator_KubernetesRequiresCA2973=== PAUSE TestNewValidator_KubernetesRequiresCA2974=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2975=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2976=== RUN TestPins_ReservedForMatchingRule2977=== PAUSE TestPins_ReservedForMatchingRule2978=== RUN TestPins_TopLevelShorthand2979=== PAUSE TestPins_TopLevelShorthand2980=== RUN TestPins_ConfigValidation2981=== PAUSE TestPins_ConfigValidation2982=== RUN TestScopes_LegacyProviderDefaultsToWrite2983=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2984=== RUN TestScopes_Rules2985=== PAUSE TestScopes_Rules2986=== RUN TestScopes_ConfigValidation2987=== PAUSE TestScopes_ConfigValidation2988=== CONT TestAudienceForIssuer2989--- PASS: TestAudienceForIssuer (0.00s)2990=== CONT TestValidateToken_NoMatchingProvider2991=== CONT TestPins_ConfigValidation2992=== CONT TestValidateToken_KubernetesServiceAccount2993=== CONT TestPins_ReservedForMatchingRule2994=== CONT TestPins_TopLevelShorthand2995=== CONT TestScopes_Rules2996=== CONT TestScopes_ConfigValidation2997=== CONT TestScopes_LegacyProviderDefaultsToWrite2998--- PASS: TestPins_ConfigValidation (0.00s)2999=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3000=== CONT TestValidateToken_Expired3001--- PASS: TestScopes_ConfigValidation (0.01s)3002=== CONT TestNewValidator_KubernetesRequiresCA3003=== CONT TestValidateToken_BoundSubjectMismatch30042026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60282/oidc3005--- PASS: TestScopes_Rules (0.03s)3006=== CONT TestValidateToken_WrongAudience30072026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60284/oidc3008--- PASS: TestPins_ReservedForMatchingRule (0.05s)3009=== CONT TestValidateToken_ValidToken30102026/10/01 08:27:25 http: TLS handshake error from 127.0.0.1:60287: read tcp 127.0.0.1:60286->127.0.0.1:60287: use of closed network connection3011--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)3012=== CONT TestGlobMatch3013=== RUN TestGlobMatch/foo_foo3014=== PAUSE TestGlobMatch/foo_foo3015=== RUN TestGlobMatch/foo_bar3016=== PAUSE TestGlobMatch/foo_bar3017=== RUN TestGlobMatch/*_3018=== PAUSE TestGlobMatch/*_3019=== RUN TestGlobMatch/*_anything3020=== PAUSE TestGlobMatch/*_anything3021=== RUN TestGlobMatch/foo*_foo3022=== PAUSE TestGlobMatch/foo*_foo3023=== RUN TestGlobMatch/foo*_foobar3024=== PAUSE TestGlobMatch/foo*_foobar3025=== RUN TestGlobMatch/foo*_bar3026=== PAUSE TestGlobMatch/foo*_bar3027=== RUN TestGlobMatch/*bar_bar3028=== PAUSE TestGlobMatch/*bar_bar3029=== RUN TestGlobMatch/*bar_foobar3030=== PAUSE TestGlobMatch/*bar_foobar3031=== RUN TestGlobMatch/*bar_foo3032=== PAUSE TestGlobMatch/*bar_foo3033=== RUN TestGlobMatch/foo*bar_foobar3034=== PAUSE TestGlobMatch/foo*bar_foobar3035=== RUN TestGlobMatch/foo*bar_foo123bar3036=== PAUSE TestGlobMatch/foo*bar_foo123bar3037=== RUN TestGlobMatch/foo*bar_foobarbaz3038=== PAUSE TestGlobMatch/foo*bar_foobarbaz3039=== RUN TestGlobMatch/*/*_foo/bar3040=== PAUSE TestGlobMatch/*/*_foo/bar3041=== RUN TestGlobMatch/*/*_foo3042=== PAUSE TestGlobMatch/*/*_foo3043=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3044=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3045=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03046=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03047=== RUN TestGlobMatch/refs/*/main_refs/heads/main3048=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3049=== RUN TestGlobMatch/fo?_foo3050=== PAUSE TestGlobMatch/fo?_foo3051=== RUN TestGlobMatch/fo?_fo3052=== PAUSE TestGlobMatch/fo?_fo3053=== RUN TestGlobMatch/fo?_fooo3054=== PAUSE TestGlobMatch/fo?_fooo3055=== RUN TestGlobMatch/?oo_foo3056=== PAUSE TestGlobMatch/?oo_foo3057=== RUN TestGlobMatch/?oo_boo3058=== PAUSE TestGlobMatch/?oo_boo3059=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3060=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3061=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3062=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3063=== CONT TestValidateToken_MultipleProviders30642026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60289/oidc3065--- PASS: TestValidateToken_Expired (0.05s)3066=== CONT TestValidateToken_BoundClaimsMismatch30672026/10/01 08:27:25 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233068--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)3069=== CONT TestGlobMatch/foo_foo3070=== CONT TestGlobMatch/*/*_foo/bar3071=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3072=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3073=== CONT TestGlobMatch/?oo_boo3074=== CONT TestGlobMatch/?oo_foo3075=== CONT TestGlobMatch/fo?_fooo3076=== CONT TestGlobMatch/fo?_fo3077=== CONT TestGlobMatch/fo?_foo3078=== CONT TestGlobMatch/refs/*/main_refs/heads/main3079=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03080=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3081=== CONT TestGlobMatch/*/*_foo3082=== CONT TestGlobMatch/*bar_bar3083=== CONT TestGlobMatch/foo*bar_foobarbaz3084=== CONT TestGlobMatch/foo*bar_foo123bar3085=== CONT TestGlobMatch/foo*bar_foobar3086=== CONT TestGlobMatch/*bar_foo3087=== CONT TestGlobMatch/*bar_foobar3088=== CONT TestGlobMatch/foo*_bar3089=== CONT TestGlobMatch/foo*_foobar3090=== CONT TestGlobMatch/foo*_foo3091=== CONT TestGlobMatch/*_anything3092=== CONT TestGlobMatch/*_3093=== CONT TestGlobMatch/foo_bar3094--- PASS: TestGlobMatch (0.00s)3095 --- PASS: TestGlobMatch/foo_foo (0.00s)3096 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3097 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3098 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3099 --- PASS: TestGlobMatch/?oo_boo (0.00s)3100 --- PASS: TestGlobMatch/?oo_foo (0.00s)3101 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3102 --- PASS: TestGlobMatch/fo?_fo (0.00s)3103 --- PASS: TestGlobMatch/fo?_foo (0.00s)3104 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3105 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3106 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3107 --- PASS: TestGlobMatch/*/*_foo (0.00s)3108 --- PASS: TestGlobMatch/*bar_bar (0.00s)3109 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3110 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3111 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3112 --- PASS: TestGlobMatch/*bar_foo (0.00s)3113 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3114 --- PASS: TestGlobMatch/foo*_bar (0.00s)3115 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3116 --- PASS: TestGlobMatch/foo*_foo (0.00s)3117 --- PASS: TestGlobMatch/*_anything (0.00s)3118 --- PASS: TestGlobMatch/*_ (0.00s)3119 --- PASS: TestGlobMatch/foo_bar (0.00s)31202026/10/01 08:27:25 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6029331212026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60295/oidc3122--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)3123--- PASS: TestValidateToken_WrongAudience (0.08s)31242026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60298/oidc3125--- PASS: TestPins_TopLevelShorthand (0.13s)31262026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60300/oidc3127--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.13s)31282026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60302/oidc3129--- PASS: TestValidateToken_ValidToken (0.10s)31302026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60304/oidc3131--- PASS: TestValidateToken_BoundSubjectMismatch (0.15s)31322026/10/01 08:27:25 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:60288/oidc3133--- PASS: TestValidateToken_NoMatchingProvider (0.16s)31342026/10/01 08:27:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60309/oidc3135--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)31362026/10/01 08:27:25 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:60308/oidc31372026/10/01 08:27:25 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:60311/oidc3138--- PASS: TestValidateToken_MultipleProviders (0.20s)3139PASS3140Running hook tests...3141=== RUN TestSendPathsEmpty3142=== PAUSE TestSendPathsEmpty3143=== RUN TestQueueEnqueueAndFetch3144=== PAUSE TestQueueEnqueueAndFetch3145=== RUN TestQueueDeduplication3146=== PAUSE TestQueueDeduplication3147=== RUN TestQueueRemove3148=== PAUSE TestQueueRemove3149=== RUN TestQueueFetchBatchLimit3150=== PAUSE TestQueueFetchBatchLimit3151=== RUN TestQueueRetryMovesToBack3152=== PAUSE TestQueueRetryMovesToBack3153=== RUN TestQueueFetchRemoveLifecycle3154=== PAUSE TestQueueFetchRemoveLifecycle3155=== RUN TestQueueConcurrentWriters3156=== PAUSE TestQueueConcurrentWriters3157=== RUN TestQueueRemoveLargeClosure3158=== PAUSE TestQueueRemoveLargeClosure3159=== RUN TestServerClientIntegration3160=== PAUSE TestServerClientIntegration3161=== RUN TestServerQueueError3162=== PAUSE TestServerQueueError3163=== RUN TestGetListenerSocketActivation3164 server_test.go:210: === RUN TestGetListenerSocketActivation3165 --- PASS: TestGetListenerSocketActivation (0.00s)3166 PASS3167 3168--- PASS: TestGetListenerSocketActivation (0.01s)3169=== RUN TestDrainIsolatesPoisonPath3170=== PAUSE TestDrainIsolatesPoisonPath3171=== RUN TestRunNotBlockedByPoisonHead3172=== PAUSE TestRunNotBlockedByPoisonHead3173=== RUN TestDrainGivesUpWhenServerDown3174=== PAUSE TestDrainGivesUpWhenServerDown3175=== RUN TestFailedPathPrunedByLaterClosure3176=== PAUSE TestFailedPathPrunedByLaterClosure3177=== RUN TestWorkerUploadsAndRemoves3178=== PAUSE TestWorkerUploadsAndRemoves3179=== RUN TestWorkerSkipsGCdPaths3180=== PAUSE TestWorkerSkipsGCdPaths3181=== RUN TestWorkerPrunesClosureDeps3182=== PAUSE TestWorkerPrunesClosureDeps3183=== RUN TestDrainTimeout3184=== PAUSE TestDrainTimeout3185=== CONT TestSendPathsEmpty3186=== CONT TestServerQueueError3187--- PASS: TestSendPathsEmpty (0.00s)3188=== CONT TestQueueFetchBatchLimit3189=== CONT TestQueueRetryMovesToBack3190=== CONT TestQueueDeduplication3191=== CONT TestQueueRemoveLargeClosure3192=== CONT TestQueueConcurrentWriters3193=== CONT TestQueueRemove3194=== CONT TestQueueFetchRemoveLifecycle3195=== CONT TestServerClientIntegration3196=== CONT TestWorkerUploadsAndRemoves31972026/10/01 08:27:26 ERROR Failed to queue paths error="permission denied" count=13198--- PASS: TestServerQueueError (0.00s)3199=== CONT TestQueueEnqueueAndFetch3200--- PASS: TestServerClientIntegration (0.00s)3201=== CONT TestRunNotBlockedByPoisonHead3202--- PASS: TestQueueEnqueueAndFetch (0.01s)3203=== CONT TestFailedPathPrunedByLaterClosure32042026/10/01 08:27:26 INFO Upload queue status pending=33205--- PASS: TestQueueRemove (0.01s)3206=== CONT TestWorkerPrunesClosureDeps32072026/10/01 08:27:26 INFO Uploading batch count=132082026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=13209--- PASS: TestQueueDeduplication (0.01s)3210=== CONT TestDrainTimeout32112026/10/01 08:27:26 INFO Upload queue status pending=232122026/10/01 08:27:26 INFO Uploading batch count=23213--- PASS: TestQueueRetryMovesToBack (0.01s)3214=== CONT TestWorkerSkipsGCdPaths3215--- PASS: TestQueueFetchBatchLimit (0.01s)3216=== CONT TestDrainIsolatesPoisonPath3217--- PASS: TestQueueFetchRemoveLifecycle (0.01s)3218=== CONT TestDrainGivesUpWhenServerDown32192026/10/01 08:27:26 INFO Uploading batch count=132202026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=132212026/10/01 08:27:26 INFO Upload queue status pending=232222026/10/01 08:27:26 INFO Uploading batch count=132232026/10/01 08:27:26 INFO Uploading batch count=132242026/10/01 08:27:26 INFO Uploading batch count=232252026/10/01 08:27:26 INFO Uploading batch count=132262026/10/01 08:27:26 INFO Upload queue status pending=232272026/10/01 08:27:26 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-86274-2014532869/TestWorkerSkipsGCdPaths2964116170/002/nonexistent32282026/10/01 08:27:26 INFO Uploading batch count=132292026/10/01 08:27:26 INFO Uploading batch count=432302026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=432312026/10/01 08:27:26 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-86274-2014532869/TestDrainIsolatesPoisonPath19926750/002/bbb32322026/10/01 08:27:26 INFO Uploading batch count=132332026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=13234--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)32352026/10/01 08:27:26 INFO Uploading batch count=232362026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=232372026/10/01 08:27:26 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-86274-2014532869/TestDrainGivesUpWhenServerDown2205211967/002/a32382026/10/01 08:27:26 INFO Uploading batch count=132392026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=132402026/10/01 08:27:26 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-86274-2014532869/TestDrainGivesUpWhenServerDown2205211967/002/b32412026/10/01 08:27:26 INFO Uploading batch count=132422026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=132432026/10/01 08:27:26 INFO Uploading batch count=232442026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=232452026/10/01 08:27:26 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-86274-2014532869/TestDrainGivesUpWhenServerDown2205211967/002/c32462026/10/01 08:27:26 ERROR Drain finished with paths left in queue remaining=132472026/10/01 08:27:26 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-86274-2014532869/TestDrainGivesUpWhenServerDown2205211967/002/d32482026/10/01 08:27:26 INFO Uploading batch count=232492026/10/01 08:27:26 ERROR Upload failed error="upload failed" count=232502026/10/01 08:27:26 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-86274-2014532869/TestDrainGivesUpWhenServerDown2205211967/002/e32512026/10/01 08:27:26 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-86274-2014532869/TestDrainGivesUpWhenServerDown2205211967/002/f32522026/10/01 08:27:26 ERROR Drain finished with paths left in queue remaining=103253--- PASS: TestDrainIsolatesPoisonPath (0.01s)3254--- PASS: TestDrainGivesUpWhenServerDown (0.01s)3255--- PASS: TestWorkerUploadsAndRemoves (0.03s)3256--- PASS: TestWorkerPrunesClosureDeps (0.02s)3257--- PASS: TestWorkerSkipsGCdPaths (0.02s)3258--- PASS: TestQueueRemoveLargeClosure (0.05s)3259--- PASS: TestQueueConcurrentWriters (0.16s)32602026/10/01 08:27:26 ERROR Upload failed error="context deadline exceeded" count=232612026/10/01 08:27:26 ERROR Drain finished with paths left in queue remaining=43262--- PASS: TestDrainTimeout (0.21s)32632026/10/01 08:27:27 INFO Uploading batch count=132642026/10/01 08:27:27 INFO Uploading batch count=132652026/10/01 08:27:27 INFO Uploading batch count=132662026/10/01 08:27:27 ERROR Upload failed error="upload failed" count=132672026/10/01 08:27:27 INFO Uploading batch count=132682026/10/01 08:27:27 ERROR Upload failed error="upload failed" count=132692026/10/01 08:27:27 INFO Uploading batch count=132702026/10/01 08:27:27 ERROR Upload failed error="upload failed" count=132712026/10/01 08:27:27 INFO Uploading batch count=132722026/10/01 08:27:27 ERROR Upload failed error="upload failed" count=132732026/10/01 08:27:27 ERROR Drain finished with paths left in queue remaining=13274--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3275PASS