niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #264
· 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.06s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestScriptTokenScriptFails96=== CONT TestDoWithRetry_BodyReplayedViaGetBody97=== CONT TestScriptTokenBadJSON98=== CONT TestScriptTokenEmptyToken99=== CONT TestScriptTokenCachesUntilRefresh100=== CONT TestScriptTokenNoExpiryRerunsEveryCall101=== CONT TestFileTokenEmpty102=== CONT TestFileTokenMissing103=== CONT TestFileTokenReadsAndCaches104--- PASS: TestFileTokenMissing (0.00s)105=== CONT TestStaticToken106--- PASS: TestStaticToken (0.00s)107=== CONT TestSetClientTLSErrors108--- PASS: TestFileTokenEmpty (0.00s)109=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1102026/09/23 13:17:50 WARN Rate limiter enabled after throttle name=server-test rate=51112026/09/23 13:17:50 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57935112--- PASS: TestFileTokenReadsAndCaches (0.00s)113=== CONT TestSetClientTLS114=== CONT TestClientSignaturesByStorePath115=== CONT TestStreamPushReportsSignatures116=== CONT TestStreamPushRequestLine117--- PASS: TestDoServerRequestAttachesToken (0.01s)118--- PASS: TestScriptTokenScriptFails (0.01s)119--- PASS: TestClientSignaturesByStorePath (0.00s)1202026/09/23 13:17:50 WARN Rate limiter backed off name=server-test rate=51212026/09/23 13:17:50 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57935122=== RUN TestSetClientTLSErrors/missing_cert_file123=== PAUSE TestSetClientTLSErrors/missing_cert_file124=== RUN TestSetClientTLSErrors/missing_key_file125=== PAUSE TestSetClientTLSErrors/missing_key_file126=== RUN TestSetClientTLSErrors/missing_ca_file127=== PAUSE TestSetClientTLSErrors/missing_ca_file128=== RUN TestSetClientTLSErrors/invalid_ca_file129=== PAUSE TestSetClientTLSErrors/invalid_ca_file130=== CONT TestStreamPushGivesUpOnDeadServer1312026/09/23 13:17:50 ERROR Upload failed error="connection refused" count=201322026/09/23 13:17:50 ERROR Server seems unavailable, giving up on batch untried=17133--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)134=== CONT TestStreamPushIsolatesFailures1352026/09/23 13:17:50 ERROR Upload failed error="bad path" count=3136--- PASS: TestStreamPushIsolatesFailures (0.00s)137=== CONT TestStreamPushBatchesUnderLoad138--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)139=== CONT TestStreamPushReportsEveryPath140--- PASS: TestStreamPushReportsEveryPath (0.00s)141=== CONT TestShellSplitErrors1422026/09/23 13:17:50 ERROR Upload failed error=boom count=1143--- PASS: TestShellSplitErrors (0.00s)144=== CONT TestShellSplit145--- PASS: TestShellSplit (0.00s)146=== CONT TestScriptTokenEmptyCommand147--- PASS: TestScriptTokenEmptyCommand (0.00s)148=== CONT TestEncodeNixBase32WithRealHash149--- PASS: TestEncodeNixBase32WithRealHash (0.00s)150=== CONT TestResolveStorePath1512026/09/23 13:17:50 ERROR Upload failed error=boom count=1152--- PASS: TestStreamPushReportsSignatures (0.00s)153=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1542026/09/23 13:17:50 WARN Rate limiter enabled after throttle name=server-test rate=5155--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)156=== CONT TestRateLimiterFeedback157=== RUN TestRateLimiterFeedback/429_enables_limiter158=== PAUSE TestRateLimiterFeedback/429_enables_limiter159=== RUN TestRateLimiterFeedback/503_enables_limiter160=== PAUSE TestRateLimiterFeedback/503_enables_limiter161=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter162=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter163=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter164=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter165=== CONT TestPathInfoCACompatibility166=== RUN TestPathInfoCACompatibility/null_ca_field167=== PAUSE TestPathInfoCACompatibility/null_ca_field168=== RUN TestPathInfoCACompatibility/old_string_format_-_text169--- PASS: TestResolveStorePath (0.00s)170=== CONT TestParsePathInfoJSONMultiplePaths171=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths172=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths173=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text174=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive175=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive176=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths177=== RUN TestPathInfoCACompatibility/new_structured_format_-_text178=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text179=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths180=== CONT TestParsePathInfoJSON181=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method182=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method183=== CONT TestPathInfoHashCompatibility184=== RUN TestParsePathInfoJSON/Nix_format185=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)186=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)187=== PAUSE TestParsePathInfoJSON/Nix_format188=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon190=== RUN TestParsePathInfoJSON/Lix_format191=== PAUSE TestParsePathInfoJSON/Lix_format192=== RUN TestParsePathInfoJSON/empty_input193=== PAUSE TestParsePathInfoJSON/empty_input194=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI195=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI196=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512198=== RUN TestParsePathInfoJSON/whitespace_only199=== CONT TestGetStorePathHash200=== PAUSE TestParsePathInfoJSON/whitespace_only201=== RUN TestGetStorePathHash/valid_store_path202=== PAUSE TestGetStorePathHash/valid_store_path203=== RUN TestParsePathInfoJSON/invalid_JSON204=== RUN TestGetStorePathHash/basename_without_hyphen_should_error205=== PAUSE TestParsePathInfoJSON/invalid_JSON206=== CONT TestConvertHashToNix32207=== RUN TestConvertHashToNix32/SRI_format_to_Nix32208=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32209=== RUN TestSetClientTLS/rejects_connection_without_client_cert210=== RUN TestConvertHashToNix32/already_Nix32_format211=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert212=== PAUSE TestConvertHashToNix32/already_Nix32_format213=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA214=== RUN TestConvertHashToNix32/invalid_format215=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA216=== RUN TestSetClientTLS/preserves_debug_logging_transport217=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error218=== PAUSE TestConvertHashToNix32/invalid_format219=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error220=== CONT TestDumpPathWriterError221=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error222=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error223=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error224=== PAUSE TestSetClientTLS/preserves_debug_logging_transport225=== CONT TestEncodeNixBase32226=== RUN TestEncodeNixBase32/test_string_hash227=== PAUSE TestEncodeNixBase32/test_string_hash228=== RUN TestEncodeNixBase32/empty_input229=== PAUSE TestEncodeNixBase32/empty_input230=== CONT TestDumpPathSingleFile231=== CONT TestFilterOversizedClosures232=== RUN TestFilterOversizedClosures/no_limit_keeps_everything233=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything234=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped235=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped236=== RUN TestFilterOversizedClosures/all_closures_skipped237=== PAUSE TestFilterOversizedClosures/all_closures_skipped238=== CONT TestPartSizeForNAR239=== RUN TestPartSizeForNAR/zero_stays_at_minimum240=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum241=== RUN TestPartSizeForNAR/small_stays_at_minimum242=== PAUSE TestPartSizeForNAR/small_stays_at_minimum243=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum244=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum245=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts246=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts247=== RUN TestPartSizeForNAR/1_TiB248=== PAUSE TestPartSizeForNAR/1_TiB249=== RUN TestPartSizeForNAR/5_TiB_S3_max_object250=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object251=== RUN TestPartSizeForNAR/capped_at_5_GiB252=== PAUSE TestPartSizeForNAR/capped_at_5_GiB253=== CONT TestUploadMultipart_PartsInParallel254--- PASS: TestScriptTokenEmptyToken (0.01s)255=== CONT TestDumpPathMatchesNix256--- PASS: TestScriptTokenBadJSON (0.01s)257=== CONT TestCaseHackSuffix258--- PASS: TestStreamPushRequestLine (0.02s)259=== CONT TestRegisterUploadedObjectReusesConnections260--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)261=== CONT TestUploadMultipart_SupersededByPeer262=== RUN TestUploadMultipart_SupersededByPeer/exists263=== PAUSE TestUploadMultipart_SupersededByPeer/exists264=== RUN TestUploadMultipart_SupersededByPeer/missing265=== PAUSE TestUploadMultipart_SupersededByPeer/missing266=== CONT TestSetClientTLSErrors/missing_cert_file267=== CONT TestSetClientTLSErrors/invalid_ca_file268=== CONT TestSetClientTLSErrors/missing_ca_file269=== CONT TestSetClientTLSErrors/missing_key_file270--- PASS: TestSetClientTLSErrors (0.00s)271 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)272 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)273 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)274 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)275=== CONT TestRateLimiterFeedback/429_enables_limiter2762026/09/23 13:17:50 WARN Rate limiter enabled after throttle name=server-test rate=52772026/09/23 13:17:50 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:580122782026/09/23 13:17:50 WARN Rate limiter backed off name=server-test rate=5279=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter280--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)281=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter282=== CONT TestRateLimiterFeedback/503_enables_limiter283=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths284=== CONT TestPathInfoCACompatibility/null_ca_field285=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method286=== CONT TestPathInfoCACompatibility/new_structured_format_-_text287=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive288=== CONT TestPathInfoCACompatibility/old_string_format_-_text289--- PASS: TestPathInfoCACompatibility (0.00s)290 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)291 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)292 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)293 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)294 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)295=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths296--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)297 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)298 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)2992026/09/23 13:17:50 WARN Rate limiter enabled after throttle name=server-test rate=5300=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3012026/09/23 13:17:50 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:58018302=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512303=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI304=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon305--- PASS: TestPathInfoHashCompatibility (0.00s)306 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)307 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)308 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)309 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)310=== CONT TestParsePathInfoJSON/Nix_format311=== CONT TestParsePathInfoJSON/empty_input312=== CONT TestParsePathInfoJSON/invalid_JSON313=== CONT TestParsePathInfoJSON/whitespace_only314=== CONT TestParsePathInfoJSON/Lix_format315--- PASS: TestParsePathInfoJSON (0.00s)316 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)317 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)318 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)319 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)320 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)321=== CONT TestConvertHashToNix32/SRI_format_to_Nix32322=== CONT TestConvertHashToNix32/invalid_format323=== CONT TestGetStorePathHash/valid_store_path324=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error325=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error326=== CONT TestGetStorePathHash/basename_without_hyphen_should_error327--- PASS: TestGetStorePathHash (0.00s)328 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)329 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)330 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)331 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)332=== CONT TestConvertHashToNix32/already_Nix32_format333--- PASS: TestConvertHashToNix32 (0.00s)334 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)335 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)336 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)337=== CONT TestSetClientTLS/rejects_connection_without_client_cert3382026/09/23 13:17:50 WARN Rate limiter backed off name=server-test rate=5339--- PASS: TestRateLimiterFeedback (0.00s)340 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)341 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)342 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)343 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)344=== CONT TestEncodeNixBase32/test_string_hash345=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA346--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)347=== CONT TestSetClientTLS/preserves_debug_logging_transport348=== CONT TestEncodeNixBase32/empty_input349--- PASS: TestEncodeNixBase32 (0.00s)350 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)351 --- PASS: TestEncodeNixBase32/empty_input (0.00s)352=== CONT TestFilterOversizedClosures/no_limit_keeps_everything353=== CONT TestFilterOversizedClosures/all_closures_skipped3542026/09/23 13:17:50 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=50355=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3562026/09/23 13:17:50 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=2000357--- PASS: TestFilterOversizedClosures (0.00s)358 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)359 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)360 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)361=== CONT TestPartSizeForNAR/zero_stays_at_minimum362=== CONT TestPartSizeForNAR/1_TiB363=== CONT TestPartSizeForNAR/capped_at_5_GiB364=== CONT TestPartSizeForNAR/5_TiB_S3_max_object365=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum366=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts367=== CONT TestPartSizeForNAR/small_stays_at_minimum368--- PASS: TestPartSizeForNAR (0.00s)369 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)371 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)372 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)373 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)375 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)376=== CONT TestUploadMultipart_SupersededByPeer/exists377=== CONT TestUploadMultipart_SupersededByPeer/missing378--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)379 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)380 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)381--- PASS: TestDumpPathWriterError (0.04s)3822026/09/23 13:17:50 http: TLS handshake error from 127.0.0.1:58020: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.06s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_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-59446-2641137695/postgres4131818531/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-59446-2641137695/postgres4131818531/data -l logfile start421422/nix/var/nix/builds/nix-59446-2641137695/postgres4131818531:5432 - no response4232026-09-23 13:17:52.013 UTC [59484] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-23 13:17:52.013 UTC [59484] LOG: listening on Unix socket "/nix/var/nix/builds/nix-59446-2641137695/postgres4131818531/.s.PGSQL.5432"4252026-09-23 13:17:52.015 UTC [59491] LOG: database system was shut down at 2026-09-23 13:17:51 UTC4262026-09-23 13:17:52.016 UTC [59484] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-59446-2641137695/postgres4131818531:5432 - accepting connections428{"timestamp":"2026-09-23T13:17:52.2287Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e6fecbfb-2bd7-4b80-8ad6-8e31d79b2de1","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":463,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}429{"timestamp":"2026-09-23T13:17:52.332367Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2b9e8307-246e-4864-82ef-042be40461e8","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":463,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-09-23 13:17:52.526 UTC [59521] ERROR: relation "goose_db_version" does not exist at character 364722026-09-23 13:17:52.526 UTC [59521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/09/23 13:17:52 OK 20241026095416_initial_model.sql (3.8ms)4742026/09/23 13:17:52 OK 20251210153512_drop_unused_gin_index.sql (498.58µs)4752026/09/23 13:17:52 OK 20251218171726_add_pins.sql (862.88µs)4762026/09/23 13:17:52 OK 20260628120000_add_object_size_and_stats.sql (835.71µs)4772026/09/23 13:17:52 OK 20260905000000_add_claims.sql (1.03ms)4782026/09/23 13:17:52 OK 20260920000000_drop_claims.sql (582.21µs)4792026/09/23 13:17:52 OK 20260923120000_add_pushes.sql (410.21µs)4802026/09/23 13:17:52 goose: successfully migrated database to version: 202609231200004812026/09/23 13:17:52 OK 1_commit_pending_closure.sql (869.17µs)4822026/09/23 13:17:52 OK 2_object_stats_trigger.sql (203µs)4832026/09/23 13:17:52 OK 3_commit_push.sql (196.75µs)4842026/09/23 13:17:52 goose: up to current file version: 34852026/09/23 13:17:52 INFO lead: acquired remote=192.0.2.1:12344862026/09/23 13:17:53 INFO lead: released remote=192.0.2.1:12344872026/09/23 13:17:53 INFO lead: acquired remote=192.0.2.1:12344882026/09/23 13:17:53 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.81s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-09-23 13:17:53.346 UTC [59525] ERROR: relation "goose_db_version" does not exist at character 364942026-09-23 13:17:53.346 UTC [59525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/09/23 13:17:53 OK 20241026095416_initial_model.sql (4.14ms)4962026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (476.04µs)4972026/09/23 13:17:53 OK 20251218171726_add_pins.sql (1.03ms)4982026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (1.06ms)4992026/09/23 13:17:53 OK 20260905000000_add_claims.sql (1.21ms)5002026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (715.13µs)5012026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (449.25µs)5022026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200005032026/09/23 13:17:53 OK 1_commit_pending_closure.sql (966.25µs)5042026/09/23 13:17:53 OK 2_object_stats_trigger.sql (237.13µs)5052026/09/23 13:17:53 OK 3_commit_push.sql (230.96µs)5062026/09/23 13:17:53 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.17s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestGCTaskStore_StartNew513=== PAUSE TestGCTaskStore_StartNew514=== RUN TestGCTaskStore_DeduplicateSameParams515=== PAUSE TestGCTaskStore_DeduplicateSameParams516=== RUN TestGCTaskStore_ConflictDifferentParams517=== PAUSE TestGCTaskStore_ConflictDifferentParams518=== RUN TestGCTaskStore_GetEmpty519=== PAUSE TestGCTaskStore_GetEmpty520=== RUN TestGCTaskStore_GetReturnsLatest521=== PAUSE TestGCTaskStore_GetReturnsLatest522=== RUN TestGCTaskStore_CompletedAllowsNewTask523=== PAUSE TestGCTaskStore_CompletedAllowsNewTask524=== RUN TestGCTaskStore_PhaseUpdates525=== PAUSE TestGCTaskStore_PhaseUpdates526=== RUN TestGCTaskStore_Fail527=== PAUSE TestGCTaskStore_Fail528=== RUN TestGracefulShutdownDrainsInflight529=== PAUSE TestGracefulShutdownDrainsInflight530=== RUN TestService_healthCheckHandler531=== PAUSE TestService_healthCheckHandler532=== RUN TestService_readinessHandler533=== PAUSE TestService_readinessHandler534=== RUN TestGenerateLandingPage535=== PAUSE TestGenerateLandingPage536=== RUN TestCacheConfigHandlerMaxNarSize537=== PAUSE TestCacheConfigHandlerMaxNarSize538=== RUN TestCreatePendingClosureRejectsOversizedNAR539=== PAUSE TestCreatePendingClosureRejectsOversizedNAR540=== RUN TestNARDeduplicationMetadataUploadBug541=== PAUSE TestNARDeduplicationMetadataUploadBug542=== RUN TestMetricsInventory543=== PAUSE TestMetricsInventory544=== RUN TestService_NativeMTLS545=== PAUSE TestService_NativeMTLS546=== RUN TestServerTLSConfig547=== PAUSE TestServerTLSConfig548=== RUN TestMultipartCleanup549=== PAUSE TestMultipartCleanup550=== RUN TestObjectStatsTrigger551=== PAUSE TestObjectStatsTrigger552=== RUN TestOrphanedObjectsGC553=== PAUSE TestOrphanedObjectsGC554=== RUN TestOrphanedObjectsGCStressTest555=== PAUSE TestOrphanedObjectsGCStressTest556=== RUN TestResurrectedObjectNotDeleted557=== PAUSE TestResurrectedObjectNotDeleted558=== RUN TestCreatePin_ReservedPins559=== PAUSE TestCreatePin_ReservedPins560=== RUN TestParseSingleRange561=== PAUSE TestParseSingleRange562=== RUN TestProxyHeadersOnlyTrustedOnSocket563=== PAUSE TestProxyHeadersOnlyTrustedOnSocket564=== RUN TestIsValidCachePath565=== PAUSE TestIsValidCachePath566=== RUN TestReadProxyNarinfo567=== PAUSE TestReadProxyNarinfo568=== RUN TestReadProxyNarinfoAlreadyDecompressed569=== PAUSE TestReadProxyNarinfoAlreadyDecompressed570=== RUN TestReadProxyNarStreaming571=== PAUSE TestReadProxyNarStreaming572=== RUN TestReadProxy404573=== PAUSE TestReadProxy404574=== RUN TestReadProxyInvalidPath575=== PAUSE TestReadProxyInvalidPath576=== RUN TestReadProxyHead577=== PAUSE TestReadProxyHead578=== RUN TestReadProxyConditionalGet579=== PAUSE TestReadProxyConditionalGet580=== RUN TestReadProxyRootRedirectsToIndexHTML581=== PAUSE TestReadProxyRootRedirectsToIndexHTML582=== RUN TestReadProxyDisabled583=== PAUSE TestReadProxyDisabled584=== RUN TestReadRedirectNar585=== PAUSE TestReadRedirectNar586=== RUN TestReadRedirectKeepsNarinfoProxied587=== PAUSE TestReadRedirectKeepsNarinfoProxied588=== RUN TestReadProxyRangeRequest589=== PAUSE TestReadProxyRangeRequest590=== RUN TestReadRedirectUsesPublicS3URL591=== PAUSE TestReadRedirectUsesPublicS3URL592=== RUN TestPush_OverlappingRootsStoreOneRowPerKey593=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey594=== RUN TestPush_CompleteCommitsEveryRoot595=== PAUSE TestPush_CompleteCommitsEveryRoot596=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected597=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected598=== RUN TestPush_RejectsBadRequests599=== PAUSE TestPush_RejectsBadRequests600=== RUN TestPush_SignsNarinfosOfItsPendingObjects601=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects602=== RUN TestRedundantMultipartUpload603=== PAUSE TestRedundantMultipartUpload604=== RUN TestCompleteMultipartUpload_ErrorButObjectExists605=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists606=== RUN TestCompletedNarNotReofferedAcrossClosures607=== PAUSE TestCompletedNarNotReofferedAcrossClosures608=== RUN TestPresignedUploadRegisteredBeforeCommit609=== PAUSE TestPresignedUploadRegisteredBeforeCommit610=== RUN TestService_Rustfstest611=== PAUSE TestService_Rustfstest612=== RUN TestParseSize613=== PAUSE TestParseSize614=== RUN TestSkippedUploadsHandler615=== PAUSE TestSkippedUploadsHandler616=== RUN TestSystemdListenerNotActivated617--- PASS: TestSystemdListenerNotActivated (0.00s)618=== RUN TestWatchdogBeatsWhenHealthy619--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)620=== RUN TestWatchdogSkipsWhenUnhealthy6212026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6302026/09/23 13:17:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"631--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)632=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle634=== RUN TestProxyWriteTimeout635=== PAUSE TestProxyWriteTimeout636=== RUN TestIsValidUploadKey637=== PAUSE TestIsValidUploadKey638=== RUN TestUploadHandlersRejectInvalidKeys639=== PAUSE TestUploadHandlersRejectInvalidKeys640=== RUN TestUploadHandlersRejectOversizedBody641=== PAUSE TestUploadHandlersRejectOversizedBody642=== RUN TestService_cleanupPendingClosuresHandler643=== PAUSE TestService_cleanupPendingClosuresHandler644=== RUN TestService_createPendingClosureHandler645=== PAUSE TestService_createPendingClosureHandler646=== RUN TestService_verifyS3Integrity647=== PAUSE TestService_verifyS3Integrity648=== RUN TestCompleteMultipartUnregistered649=== PAUSE TestCompleteMultipartUnregistered650=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT651=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT652=== CONT TestReadProxyRangeRequest653=== CONT TestService_AuthMiddleware654=== CONT TestParseSize655=== CONT TestPush_SignsNarinfosOfItsPendingObjects656--- PASS: TestParseSize (0.00s)657=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT658=== CONT TestCompletedNarNotReofferedAcrossClosures659=== CONT TestReadRedirectKeepsNarinfoProxied660=== CONT TestService_Rustfstest661=== CONT TestPush_RejectsBadRequests662=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected663=== CONT TestPush_CompleteCommitsEveryRoot6642026-09-23 13:17:53.935 UTC [59548] ERROR: relation "goose_db_version" does not exist at character 366652026-09-23 13:17:53.935 UTC [59548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6662026-09-23 13:17:53.935 UTC [59547] ERROR: relation "goose_db_version" does not exist at character 366672026-09-23 13:17:53.935 UTC [59547] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6682026-09-23 13:17:53.959 UTC [59549] ERROR: relation "goose_db_version" does not exist at character 366692026-09-23 13:17:53.959 UTC [59549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6702026/09/23 13:17:53 OK 20241026095416_initial_model.sql (20.29ms)6712026/09/23 13:17:53 OK 20241026095416_initial_model.sql (20.26ms)6722026-09-23 13:17:53.966 UTC [59550] ERROR: relation "goose_db_version" does not exist at character 366732026-09-23 13:17:53.966 UTC [59550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6742026-09-23 13:17:53.966 UTC [59551] ERROR: relation "goose_db_version" does not exist at character 366752026-09-23 13:17:53.966 UTC [59551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6762026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)6772026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)6782026-09-23 13:17:53.966 UTC [59552] ERROR: relation "goose_db_version" does not exist at character 366792026-09-23 13:17:53.966 UTC [59552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6802026/09/23 13:17:53 OK 20251218171726_add_pins.sql (1.39ms)6812026-09-23 13:17:53.967 UTC [59553] ERROR: relation "goose_db_version" does not exist at character 366822026-09-23 13:17:53.967 UTC [59553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6832026-09-23 13:17:53.969 UTC [59556] ERROR: relation "goose_db_version" does not exist at character 366842026-09-23 13:17:53.969 UTC [59556] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (1.17ms)6862026/09/23 13:17:53 OK 20251218171726_add_pins.sql (2.47ms)6872026-09-23 13:17:53.969 UTC [59554] ERROR: relation "goose_db_version" does not exist at character 366882026-09-23 13:17:53.969 UTC [59554] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6892026-09-23 13:17:53.969 UTC [59555] ERROR: relation "goose_db_version" does not exist at character 366902026-09-23 13:17:53.969 UTC [59555] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6912026/09/23 13:17:53 OK 20260905000000_add_claims.sql (1.9ms)6922026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (2.11ms)6932026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (886.58µs)6942026/09/23 13:17:53 OK 20241026095416_initial_model.sql (5.51ms)6952026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (1.03ms)6962026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200006972026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (657.33µs)6982026/09/23 13:17:53 OK 20260905000000_add_claims.sql (1.81ms)6992026/09/23 13:17:53 OK 20260920000000_drop_claims.sql (1.35ms)7002026/09/23 13:17:53 OK 1_commit_pending_closure.sql (1.48ms)7012026/09/23 13:17:53 OK 20251218171726_add_pins.sql (2.01ms)7022026/09/23 13:17:53 OK 2_object_stats_trigger.sql (739.71µs)7032026/09/23 13:17:53 OK 3_commit_push.sql (468.5µs)7042026/09/23 13:17:53 goose: up to current file version: 37052026/09/23 13:17:53 OK 20260923120000_add_pushes.sql (1.52ms)7062026/09/23 13:17:53 goose: successfully migrated database to version: 202609231200007072026/09/23 13:17:53 OK 20260628120000_add_object_size_and_stats.sql (1.32ms)7082026/09/23 13:17:53 OK 20241026095416_initial_model.sql (6.9ms)7092026/09/23 13:17:53 OK 20241026095416_initial_model.sql (7.03ms)7102026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (831.79µs)7112026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (871.79µs)7122026/09/23 13:17:53 OK 1_commit_pending_closure.sql (1.81ms)7132026/09/23 13:17:53 OK 2_object_stats_trigger.sql (469.54µs)7142026/09/23 13:17:53 OK 20241026095416_initial_model.sql (6.36ms)7152026/09/23 13:17:53 OK 20241026095416_initial_model.sql (5.89ms)7162026/09/23 13:17:53 OK 3_commit_push.sql (333.13µs)7172026/09/23 13:17:53 goose: up to current file version: 37182026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)7192026/09/23 13:17:53 OK 20241026095416_initial_model.sql (11.34ms)7202026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (4.05ms)7212026/09/23 13:17:53 OK 20260905000000_add_claims.sql (6.49ms)7222026/09/23 13:17:53 OK 20251218171726_add_pins.sql (5.33ms)7232026/09/23 13:17:53 OK 20241026095416_initial_model.sql (11.94ms)7242026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (13.88ms)7252026/09/23 13:17:53 OK 20251218171726_add_pins.sql (19.31ms)7262026/09/23 13:17:53 OK 20251210153512_drop_unused_gin_index.sql (14.48ms)7272026/09/23 13:17:53 OK 20251218171726_add_pins.sql (16.4ms)7282026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (21.45ms)7292026/09/23 13:17:54 OK 20251218171726_add_pins.sql (21.99ms)7302026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (21.99ms)7312026/09/23 13:17:54 OK 20251218171726_add_pins.sql (7.45ms)7322026/09/23 13:17:54 OK 20241026095416_initial_model.sql (31.54ms)7332026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (8.35ms)7342026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1ms)7352026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200007362026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (7.57ms)7372026/09/23 13:17:54 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)7382026/09/23 13:17:54 OK 1_commit_pending_closure.sql (1.12ms)7392026/09/23 13:17:54 OK 20251218171726_add_pins.sql (10.1ms)7402026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (2.21ms)7412026/09/23 13:17:54 OK 2_object_stats_trigger.sql (430.38µs)7422026/09/23 13:17:54 OK 3_commit_push.sql (175.75µs)7432026/09/23 13:17:54 goose: up to current file version: 37442026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (6.42ms)7452026/09/23 13:17:54 OK 20260905000000_add_claims.sql (7.52ms)7462026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)7472026/09/23 13:17:54 OK 20260905000000_add_claims.sql (14.33ms)7482026/09/23 13:17:54 OK 20251218171726_add_pins.sql (13.65ms)7492026/09/23 13:17:54 OK 20260905000000_add_claims.sql (14.58ms)7502026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (7.68ms)7512026/09/23 13:17:54 OK 20260905000000_add_claims.sql (13.35ms)7522026/09/23 13:17:54 OK 20260905000000_add_claims.sql (8.85ms)7532026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.13ms)7542026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (766.54µs)7552026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200007562026/09/23 13:17:54 OK 20260905000000_add_claims.sql (8.44ms)7572026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.57ms)7582026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (1.95ms)7592026/09/23 13:17:54 OK 1_commit_pending_closure.sql (1ms)7602026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (1.39ms)7612026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200007622026/09/23 13:17:54 OK 2_object_stats_trigger.sql (272.21µs)7632026/09/23 13:17:54 OK 3_commit_push.sql (182.83µs)7642026/09/23 13:17:54 goose: up to current file version: 37652026/09/23 13:17:54 OK 1_commit_pending_closure.sql (743.63µs)7662026/09/23 13:17:54 OK 2_object_stats_trigger.sql (163µs)7672026/09/23 13:17:54 OK 3_commit_push.sql (169.63µs)7682026/09/23 13:17:54 goose: up to current file version: 37692026/09/23 13:17:54 OK 20260628120000_add_object_size_and_stats.sql (8.78ms)7702026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (7.05ms)7712026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200007722026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (8.95ms)7732026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (7.4ms)7742026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200007752026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (8.4ms)7762026/09/23 13:17:54 OK 1_commit_pending_closure.sql (744.29µs)7772026/09/23 13:17:54 OK 2_object_stats_trigger.sql (166.46µs)7782026/09/23 13:17:54 OK 3_commit_push.sql (153.75µs)7792026/09/23 13:17:54 goose: up to current file version: 37802026/09/23 13:17:54 OK 1_commit_pending_closure.sql (768.13µs)7812026/09/23 13:17:54 OK 2_object_stats_trigger.sql (164.21µs)7822026/09/23 13:17:54 OK 3_commit_push.sql (163.38µs)7832026/09/23 13:17:54 goose: up to current file version: 37842026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (7.13ms)7852026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200007862026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (7.38ms)7872026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200007882026/09/23 13:17:54 OK 1_commit_pending_closure.sql (773.25µs)7892026/09/23 13:17:54 OK 1_commit_pending_closure.sql (779.92µs)7902026/09/23 13:17:54 OK 20260905000000_add_claims.sql (8.68ms)7912026/09/23 13:17:54 OK 2_object_stats_trigger.sql (183µs)7922026/09/23 13:17:54 OK 2_object_stats_trigger.sql (175.54µs)7932026/09/23 13:17:54 OK 3_commit_push.sql (170.04µs)7942026/09/23 13:17:54 goose: up to current file version: 37952026/09/23 13:17:54 OK 3_commit_push.sql (173.42µs)7962026/09/23 13:17:54 goose: up to current file version: 37972026/09/23 13:17:54 OK 20260920000000_drop_claims.sql (8.35ms)7982026/09/23 13:17:54 OK 20260923120000_add_pushes.sql (395.42µs)7992026/09/23 13:17:54 goose: successfully migrated database to version: 202609231200008002026/09/23 13:17:54 OK 1_commit_pending_closure.sql (732.54µs)8012026/09/23 13:17:54 OK 2_object_stats_trigger.sql (178.25µs)8022026/09/23 13:17:54 OK 3_commit_push.sql (185.79µs)8032026/09/23 13:17:54 goose: up to current file version: 38042026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures805--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.49s)806=== CONT TestPush_OverlappingRootsStoreOneRowPerKey807--- PASS: TestReadRedirectKeepsNarinfoProxied (0.60s)808=== CONT TestReadRedirectUsesPublicS3URL8092026/09/23 13:17:54 INFO Received uploads request method=POST path=/api/pending_closures8102026/09/23 13:17:54 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"811--- PASS: TestService_AuthMiddleware (0.93s)812=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8132026/09/23 13:17:54 INFO Received push request method=POST path=/api/pushes8142026/09/23 13:17:54 INFO Received complete push request method=POST path=/api/pushes/1/complete815--- PASS: TestPush_CompleteCommitsEveryRoot (1.18s)816=== CONT TestRedundantMultipartUpload817=== RUN TestPush_RejectsBadRequests/no_roots818=== PAUSE TestPush_RejectsBadRequests/no_roots819=== RUN TestPush_RejectsBadRequests/no_objects820=== PAUSE TestPush_RejectsBadRequests/no_objects821=== RUN TestPush_RejectsBadRequests/bad_root822=== PAUSE TestPush_RejectsBadRequests/bad_root823=== RUN TestPush_RejectsBadRequests/root_not_in_objects824=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects825=== CONT TestGCTaskStore_Fail826--- PASS: TestGCTaskStore_Fail (0.00s)827=== CONT TestReadRedirectNar8282026-09-23 13:17:54.972 UTC [59567] ERROR: relation "goose_db_version" does not exist at character 368292026-09-23 13:17:54.972 UTC [59567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8302026-09-23 13:17:55.102 UTC [59570] ERROR: relation "goose_db_version" does not exist at character 368312026-09-23 13:17:55.102 UTC [59570] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026/09/23 13:17:55 OK 20241026095416_initial_model.sql (80.57ms)8332026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (5.94ms)8342026/09/23 13:17:55 OK 20251218171726_add_pins.sql (20.57ms)8352026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (28.18ms)8362026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes8372026/09/23 13:17:55 OK 20260905000000_add_claims.sql (47.89ms)8382026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (33.37ms)8392026/09/23 13:17:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8402026/09/23 13:17:55 INFO Signed narinfos id=1 count=1841--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.60s)842=== CONT TestReadProxyDisabled8432026/09/23 13:17:55 OK 20241026095416_initial_model.sql (118.92ms)8442026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (8.57ms)8452026/09/23 13:17:55 goose: successfully migrated database to version: 202609231200008462026/09/23 13:17:55 OK 1_commit_pending_closure.sql (2.99ms)8472026/09/23 13:17:55 OK 2_object_stats_trigger.sql (503.38µs)8482026/09/23 13:17:55 OK 3_commit_push.sql (466.79µs)8492026/09/23 13:17:55 goose: up to current file version: 38502026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (14.21ms)8512026/09/23 13:17:55 OK 20251218171726_add_pins.sql (63.45ms)8522026-09-23 13:17:55.337 UTC [59573] ERROR: relation "goose_db_version" does not exist at character 368532026-09-23 13:17:55.337 UTC [59573] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (14.23ms)8552026/09/23 13:17:55 OK 20260905000000_add_claims.sql (42.27ms)8562026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (16.7ms)8572026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes8582026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (15.63ms)8592026/09/23 13:17:55 goose: successfully migrated database to version: 202609231200008602026/09/23 13:17:55 OK 1_commit_pending_closure.sql (3.12ms)8612026/09/23 13:17:55 OK 2_object_stats_trigger.sql (867.42µs)8622026/09/23 13:17:55 OK 3_commit_push.sql (521.75µs)8632026/09/23 13:17:55 goose: up to current file version: 38642026/09/23 13:17:55 INFO Received complete push request method=POST path=/api/pushes/1/complete8652026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes8662026/09/23 13:17:55 INFO Received complete push request method=POST path=/api/pushes/2/complete8672026-09-23 13:17:55.511 UTC [59574] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo8682026-09-23 13:17:55.511 UTC [59574] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE8692026-09-23 13:17:55.511 UTC [59574] STATEMENT: -- name: CommitPush :exec870 SELECT commit_push($1::bigint)871 872--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (1.86s)873=== CONT TestReadProxyRootRedirectsToIndexHTML8742026/09/23 13:17:55 OK 20241026095416_initial_model.sql (153.97ms)8752026/09/23 13:17:55 OK 20251210153512_drop_unused_gin_index.sql (6.96ms)8762026/09/23 13:17:55 OK 20251218171726_add_pins.sql (7.88ms)8772026/09/23 13:17:55 OK 20260628120000_add_object_size_and_stats.sql (20.45ms)8782026/09/23 13:17:55 OK 20260905000000_add_claims.sql (44.82ms)879--- PASS: TestReadProxyRangeRequest (1.99s)880=== CONT TestReadProxyConditionalGet8812026/09/23 13:17:55 OK 20260920000000_drop_claims.sql (25.7ms)8822026/09/23 13:17:55 OK 20260923120000_add_pushes.sql (9.27ms)8832026/09/23 13:17:55 goose: successfully migrated database to version: 202609231200008842026/09/23 13:17:55 OK 1_commit_pending_closure.sql (1.55ms)8852026/09/23 13:17:55 OK 2_object_stats_trigger.sql (380.92µs)8862026/09/23 13:17:55 OK 3_commit_push.sql (334.04µs)8872026/09/23 13:17:55 goose: up to current file version: 38882026/09/23 13:17:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8892026/09/23 13:17:55 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjJhNWY1MmEtYjE4My00YmI5LTk2YmEtNjY3Nzc1ZjBiMjA2LjA2OGEwNmExLThhMzEtNDk1ZS1hZDg0LTQ3MzVlNjMzNDhlOXgxNzkwMTY5NDc0NDYxNzQ4MDAw parts=128902026/09/23 13:17:55 INFO Received uploads request method=POST path=/api/pending_closures891--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.14s)892=== CONT TestReadProxyHead893--- PASS: TestService_Rustfstest (2.19s)894=== CONT TestReadProxyInvalidPath8952026-09-23 13:17:55.918 UTC [59583] ERROR: relation "goose_db_version" does not exist at character 368962026-09-23 13:17:55.918 UTC [59583] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8972026-09-23 13:17:55.972 UTC [59584] ERROR: relation "goose_db_version" does not exist at character 368982026-09-23 13:17:55.972 UTC [59584] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026/09/23 13:17:55 INFO Received push request method=POST path=/api/pushes9002026/09/23 13:17:56 OK 20241026095416_initial_model.sql (116.09ms)9012026/09/23 13:17:56 OK 20251210153512_drop_unused_gin_index.sql (6.3ms)902--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.94s)903=== CONT TestReadProxy4049042026/09/23 13:17:56 OK 20251218171726_add_pins.sql (16.63ms)9052026/09/23 13:17:56 OK 20241026095416_initial_model.sql (91.45ms)9062026/09/23 13:17:56 OK 20260628120000_add_object_size_and_stats.sql (16.51ms)9072026/09/23 13:17:56 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)9082026/09/23 13:17:56 OK 20251218171726_add_pins.sql (27.5ms)9092026/09/23 13:17:56 OK 20260905000000_add_claims.sql (39.75ms)9102026/09/23 13:17:56 OK 20260628120000_add_object_size_and_stats.sql (28.47ms)9112026/09/23 13:17:56 OK 20260920000000_drop_claims.sql (20.25ms)9122026/09/23 13:17:56 OK 20260923120000_add_pushes.sql (6.72ms)9132026/09/23 13:17:56 goose: successfully migrated database to version: 202609231200009142026/09/23 13:17:56 OK 1_commit_pending_closure.sql (2.36ms)9152026/09/23 13:17:56 OK 2_object_stats_trigger.sql (467.29µs)9162026/09/23 13:17:56 OK 3_commit_push.sql (395.38µs)9172026/09/23 13:17:56 goose: up to current file version: 39182026/09/23 13:17:56 OK 20260905000000_add_claims.sql (27.4ms)9192026/09/23 13:17:56 OK 20260920000000_drop_claims.sql (22.86ms)920--- PASS: TestReadRedirectUsesPublicS3URL (1.98s)921=== CONT TestReadProxyNarStreaming9222026/09/23 13:17:56 OK 20260923120000_add_pushes.sql (14.09ms)9232026/09/23 13:17:56 goose: successfully migrated database to version: 202609231200009242026/09/23 13:17:56 OK 1_commit_pending_closure.sql (1.9ms)9252026/09/23 13:17:56 OK 2_object_stats_trigger.sql (396.42µs)9262026/09/23 13:17:56 OK 3_commit_push.sql (350.04µs)9272026/09/23 13:17:56 goose: up to current file version: 39282026/09/23 13:17:56 INFO Received uploads request method=POST path=/api/pending_closures9292026/09/23 13:17:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9302026/09/23 13:17:56 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjJhNWY1MmEtYjE4My00YmI5LTk2YmEtNjY3Nzc1ZjBiMjA2LmZkMmJkZGFlLTA0ODQtNDBhZS1iMzM4LTQxNDhlZTA3ZGE1MngxNzkwMTY5NDc2NDI2NzcwMDAw9312026/09/23 13:17:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjJhNWY1MmEtYjE4My00YmI5LTk2YmEtNjY3Nzc1ZjBiMjA2LmZkMmJkZGFlLTA0ODQtNDBhZS1iMzM4LTQxNDhlZTA3ZGE1MngxNzkwMTY5NDc2NDI2NzcwMDAw parts=1932--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.07s)933=== CONT TestReadProxyNarinfoAlreadyDecompressed9342026/09/23 13:17:56 INFO Received uploads request method=POST path=/api/pending_closures9352026-09-23 13:17:56.703 UTC [59591] ERROR: relation "goose_db_version" does not exist at character 369362026-09-23 13:17:56.703 UTC [59591] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9372026/09/23 13:17:56 INFO Received uploads request method=POST path=/api/pending_closures9382026-09-23 13:17:56.875 UTC [59594] ERROR: relation "goose_db_version" does not exist at character 369392026-09-23 13:17:56.875 UTC [59594] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9402026-09-23 13:17:56.921 UTC [59595] ERROR: relation "goose_db_version" does not exist at character 369412026-09-23 13:17:56.921 UTC [59595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9422026/09/23 13:17:56 OK 20241026095416_initial_model.sql (148.5ms)9432026/09/23 13:17:56 OK 20251210153512_drop_unused_gin_index.sql (20.97ms)944--- PASS: TestReadRedirectNar (1.98s)945=== CONT TestReadProxyNarinfo9462026/09/23 13:17:56 OK 20251218171726_add_pins.sql (32.43ms)9472026/09/23 13:17:57 OK 20260628120000_add_object_size_and_stats.sql (36.21ms)9482026/09/23 13:17:57 OK 20260905000000_add_claims.sql (25ms)9492026/09/23 13:17:57 OK 20260920000000_drop_claims.sql (1.71ms)9502026/09/23 13:17:57 OK 20241026095416_initial_model.sql (103.43ms)9512026/09/23 13:17:57 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)9522026/09/23 13:17:57 OK 20251218171726_add_pins.sql (1.38ms)9532026/09/23 13:17:57 OK 20241026095416_initial_model.sql (91.51ms)9542026/09/23 13:17:57 OK 20260923120000_add_pushes.sql (29.85ms)9552026/09/23 13:17:57 goose: successfully migrated database to version: 202609231200009562026/09/23 13:17:57 OK 20251210153512_drop_unused_gin_index.sql (7.3ms)9572026/09/23 13:17:57 OK 1_commit_pending_closure.sql (1.96ms)9582026/09/23 13:17:57 OK 2_object_stats_trigger.sql (382.75µs)9592026/09/23 13:17:57 OK 3_commit_push.sql (350.42µs)9602026/09/23 13:17:57 goose: up to current file version: 39612026/09/23 13:17:57 OK 20260628120000_add_object_size_and_stats.sql (40.29ms)9622026-09-23 13:17:57.090 UTC [59598] ERROR: relation "goose_db_version" does not exist at character 369632026-09-23 13:17:57.090 UTC [59598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9642026/09/23 13:17:57 OK 20251218171726_add_pins.sql (35.14ms)9652026-09-23 13:17:57.113 UTC [59599] ERROR: relation "goose_db_version" does not exist at character 369662026-09-23 13:17:57.113 UTC [59599] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026/09/23 13:17:57 OK 20260905000000_add_claims.sql (40.2ms)9682026/09/23 13:17:57 OK 20260628120000_add_object_size_and_stats.sql (18.96ms)9692026/09/23 13:17:57 OK 20260920000000_drop_claims.sql (15.71ms)9702026/09/23 13:17:57 OK 20260905000000_add_claims.sql (17.23ms)9712026/09/23 13:17:57 OK 20260923120000_add_pushes.sql (16.34ms)9722026/09/23 13:17:57 goose: successfully migrated database to version: 202609231200009732026/09/23 13:17:57 OK 1_commit_pending_closure.sql (2.56ms)9742026/09/23 13:17:57 OK 2_object_stats_trigger.sql (403.17µs)9752026/09/23 13:17:57 OK 3_commit_push.sql (340.58µs)9762026/09/23 13:17:57 goose: up to current file version: 39772026/09/23 13:17:57 OK 20260920000000_drop_claims.sql (27.47ms)9782026/09/23 13:17:57 OK 20260923120000_add_pushes.sql (13.99ms)9792026/09/23 13:17:57 goose: successfully migrated database to version: 202609231200009802026/09/23 13:17:57 OK 1_commit_pending_closure.sql (1.72ms)9812026/09/23 13:17:57 OK 2_object_stats_trigger.sql (395.67µs)9822026/09/23 13:17:57 OK 3_commit_push.sql (380µs)9832026/09/23 13:17:57 goose: up to current file version: 39842026/09/23 13:17:57 OK 20241026095416_initial_model.sql (110.51ms)9852026/09/23 13:17:57 OK 20251210153512_drop_unused_gin_index.sql (11.68ms)9862026/09/23 13:17:57 OK 20241026095416_initial_model.sql (120.42ms)9872026/09/23 13:17:57 OK 20251210153512_drop_unused_gin_index.sql (9.9ms)988--- PASS: TestReadProxyDisabled (2.02s)989=== CONT TestIsValidCachePath990=== RUN TestIsValidCachePath/narinfo991=== PAUSE TestIsValidCachePath/narinfo992=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars993=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars994=== RUN TestIsValidCachePath/nar_zst995=== PAUSE TestIsValidCachePath/nar_zst996=== RUN TestIsValidCachePath/nar_xz997=== PAUSE TestIsValidCachePath/nar_xz998=== RUN TestIsValidCachePath/nar_bz2999=== PAUSE TestIsValidCachePath/nar_bz21000=== RUN TestIsValidCachePath/nar_uncompressed1001=== PAUSE TestIsValidCachePath/nar_uncompressed1002=== RUN TestIsValidCachePath/ls1003=== PAUSE TestIsValidCachePath/ls1004=== RUN TestIsValidCachePath/log1005=== PAUSE TestIsValidCachePath/log1006=== RUN TestIsValidCachePath/realisation1007=== PAUSE TestIsValidCachePath/realisation1008=== RUN TestIsValidCachePath/nix-cache-info1009=== PAUSE TestIsValidCachePath/nix-cache-info1010=== RUN TestIsValidCachePath/index.html1011=== PAUSE TestIsValidCachePath/index.html1012=== RUN TestIsValidCachePath/traversal_parent1013=== PAUSE TestIsValidCachePath/traversal_parent1014=== RUN TestIsValidCachePath/traversal_in_middle1015=== PAUSE TestIsValidCachePath/traversal_in_middle1016=== RUN TestIsValidCachePath/invalid_char_e1017=== PAUSE TestIsValidCachePath/invalid_char_e1018=== RUN TestIsValidCachePath/invalid_char_u1019=== PAUSE TestIsValidCachePath/invalid_char_u1020=== RUN TestIsValidCachePath/random_path1021=== PAUSE TestIsValidCachePath/random_path1022=== RUN TestIsValidCachePath/empty1023=== PAUSE TestIsValidCachePath/empty1024=== RUN TestIsValidCachePath/leading_slash1025=== PAUSE TestIsValidCachePath/leading_slash1026=== RUN TestIsValidCachePath/wrong_extension1027=== PAUSE TestIsValidCachePath/wrong_extension1028=== RUN TestIsValidCachePath/short_hash1029=== PAUSE TestIsValidCachePath/short_hash1030=== CONT TestProxyHeadersOnlyTrustedOnSocket10312026/09/23 13:17:57 OK 20251218171726_add_pins.sql (30.45ms)10322026/09/23 13:17:57 OK 20251218171726_add_pins.sql (38.94ms)10332026/09/23 13:17:57 OK 20260628120000_add_object_size_and_stats.sql (47.86ms)10342026/09/23 13:17:57 OK 20260628120000_add_object_size_and_stats.sql (33.18ms)10352026/09/23 13:17:57 OK 20260905000000_add_claims.sql (12.18ms)10362026/09/23 13:17:57 OK 20260920000000_drop_claims.sql (16.3ms)10372026/09/23 13:17:57 OK 20260905000000_add_claims.sql (20.49ms)10382026/09/23 13:17:57 OK 20260923120000_add_pushes.sql (3.7ms)10392026/09/23 13:17:57 goose: successfully migrated database to version: 2026092312000010402026/09/23 13:17:57 OK 1_commit_pending_closure.sql (1.86ms)10412026/09/23 13:17:57 OK 2_object_stats_trigger.sql (405.25µs)10422026/09/23 13:17:57 OK 3_commit_push.sql (335.13µs)10432026/09/23 13:17:57 goose: up to current file version: 310442026/09/23 13:17:57 OK 20260920000000_drop_claims.sql (34.21ms)10452026/09/23 13:17:57 OK 20260923120000_add_pushes.sql (15.71ms)10462026/09/23 13:17:57 goose: successfully migrated database to version: 2026092312000010472026/09/23 13:17:57 OK 1_commit_pending_closure.sql (1.64ms)10482026/09/23 13:17:57 OK 2_object_stats_trigger.sql (395.63µs)10492026/09/23 13:17:57 OK 3_commit_push.sql (378.71µs)10502026/09/23 13:17:57 goose: up to current file version: 31051--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.02s)1052=== CONT TestParseSingleRange1053=== RUN TestParseSingleRange/none1054=== PAUSE TestParseSingleRange/none1055=== RUN TestParseSingleRange/unknown_unit1056=== PAUSE TestParseSingleRange/unknown_unit1057=== RUN TestParseSingleRange/multi-range_ignored1058=== PAUSE TestParseSingleRange/multi-range_ignored1059=== RUN TestParseSingleRange/malformed_no_dash1060=== PAUSE TestParseSingleRange/malformed_no_dash1061=== RUN TestParseSingleRange/malformed_both_empty1062=== PAUSE TestParseSingleRange/malformed_both_empty1063=== RUN TestParseSingleRange/malformed_end_before_start1064=== PAUSE TestParseSingleRange/malformed_end_before_start1065=== RUN TestParseSingleRange/closed1066=== PAUSE TestParseSingleRange/closed1067=== RUN TestParseSingleRange/open-ended1068=== PAUSE TestParseSingleRange/open-ended1069=== RUN TestParseSingleRange/end_clamped_to_size1070=== PAUSE TestParseSingleRange/end_clamped_to_size1071=== RUN TestParseSingleRange/suffix1072=== PAUSE TestParseSingleRange/suffix1073=== RUN TestParseSingleRange/suffix_exceeds_size1074=== PAUSE TestParseSingleRange/suffix_exceeds_size1075=== RUN TestParseSingleRange/single_byte1076=== PAUSE TestParseSingleRange/single_byte1077=== RUN TestParseSingleRange/start_past_EOF1078=== PAUSE TestParseSingleRange/start_past_EOF1079=== RUN TestParseSingleRange/start_far_past_EOF1080=== PAUSE TestParseSingleRange/start_far_past_EOF1081=== CONT TestCreatePin_ReservedPins10822026/09/23 13:17:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58083/oidc10832026-09-23 13:17:57.624 UTC [59602] ERROR: relation "goose_db_version" does not exist at character 3610842026-09-23 13:17:57.624 UTC [59602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10852026-09-23 13:17:57.699 UTC [59605] ERROR: relation "goose_db_version" does not exist at character 3610862026-09-23 13:17:57.699 UTC [59605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1087--- PASS: TestReadProxyConditionalGet (2.13s)1088=== CONT TestResurrectedObjectNotDeleted10892026/09/23 13:17:57 OK 20241026095416_initial_model.sql (126ms)10902026/09/23 13:17:57 OK 20251210153512_drop_unused_gin_index.sql (11.91ms)10912026/09/23 13:17:57 OK 20251218171726_add_pins.sql (28.27ms)10922026/09/23 13:17:57 OK 20260628120000_add_object_size_and_stats.sql (28.87ms)10932026/09/23 13:17:57 OK 20241026095416_initial_model.sql (141.59ms)10942026/09/23 13:17:57 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)10952026/09/23 13:17:57 OK 20260905000000_add_claims.sql (97.21ms)10962026/09/23 13:17:57 OK 20251218171726_add_pins.sql (88.48ms)1097--- PASS: TestReadProxyHead (2.21s)1098=== CONT TestOrphanedObjectsGCStressTest10992026/09/23 13:17:58 OK 20260920000000_drop_claims.sql (47.18ms)11002026/09/23 13:17:58 OK 20260628120000_add_object_size_and_stats.sql (47.67ms)11012026/09/23 13:17:58 OK 20260923120000_add_pushes.sql (15.18ms)11022026/09/23 13:17:58 goose: successfully migrated database to version: 2026092312000011032026/09/23 13:17:58 OK 1_commit_pending_closure.sql (1.66ms)11042026/09/23 13:17:58 OK 2_object_stats_trigger.sql (387.46µs)11052026/09/23 13:17:58 OK 3_commit_push.sql (339.83µs)11062026/09/23 13:17:58 goose: up to current file version: 311072026/09/23 13:17:58 OK 20260905000000_add_claims.sql (41.89ms)11082026/09/23 13:17:58 OK 20260920000000_drop_claims.sql (41.41ms)11092026/09/23 13:17:58 OK 20260923120000_add_pushes.sql (9.3ms)11102026/09/23 13:17:58 goose: successfully migrated database to version: 2026092312000011112026/09/23 13:17:58 OK 1_commit_pending_closure.sql (2.46ms)11122026/09/23 13:17:58 OK 2_object_stats_trigger.sql (593.92µs)11132026/09/23 13:17:58 OK 3_commit_push.sql (473.58µs)11142026/09/23 13:17:58 goose: up to current file version: 311152026/09/23 13:17:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11162026/09/23 13:17:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjJhNWY1MmEtYjE4My00YmI5LTk2YmEtNjY3Nzc1ZjBiMjA2LmZhYzE1MWYzLWEwNDktNDM4MS04ZjVkLWJiYmRmNGFkMmU3Y3gxNzkwMTY5NDc2Njk3ODQwMDAw parts=121117--- PASS: TestRedundantMultipartUpload (3.39s)1118=== CONT TestOrphanedObjectsGC11192026-09-23 13:17:58.234 UTC [59610] ERROR: relation "goose_db_version" does not exist at character 3611202026-09-23 13:17:58.234 UTC [59610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1121--- PASS: TestReadProxyInvalidPath (2.44s)1122=== CONT TestObjectStatsTrigger11232026-09-23 13:17:58.388 UTC [59615] ERROR: relation "goose_db_version" does not exist at character 3611242026-09-23 13:17:58.388 UTC [59615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11252026/09/23 13:17:58 OK 20241026095416_initial_model.sql (115.85ms)11262026/09/23 13:17:58 OK 20251210153512_drop_unused_gin_index.sql (8.05ms)11272026/09/23 13:17:58 OK 20251218171726_add_pins.sql (18.33ms)11282026/09/23 13:17:58 OK 20260628120000_add_object_size_and_stats.sql (20.54ms)11292026/09/23 13:17:58 OK 20260905000000_add_claims.sql (26.72ms)1130--- PASS: TestReadProxy404 (2.40s)1131=== CONT TestMultipartCleanup11322026/09/23 13:17:58 OK 20260920000000_drop_claims.sql (23.49ms)11332026/09/23 13:17:58 OK 20260923120000_add_pushes.sql (14.95ms)11342026/09/23 13:17:58 goose: successfully migrated database to version: 2026092312000011352026/09/23 13:17:58 OK 1_commit_pending_closure.sql (2.16ms)11362026/09/23 13:17:58 OK 2_object_stats_trigger.sql (502.92µs)11372026/09/23 13:17:58 OK 3_commit_push.sql (429.79µs)11382026/09/23 13:17:58 goose: up to current file version: 311392026/09/23 13:17:58 OK 20241026095416_initial_model.sql (97.93ms)11402026/09/23 13:17:58 OK 20251210153512_drop_unused_gin_index.sql (8.31ms)11412026/09/23 13:17:58 OK 20251218171726_add_pins.sql (9.63ms)11422026/09/23 13:17:58 OK 20260628120000_add_object_size_and_stats.sql (18.09ms)11432026/09/23 13:17:58 OK 20260905000000_add_claims.sql (28.03ms)11442026/09/23 13:17:58 OK 20260920000000_drop_claims.sql (10.99ms)11452026/09/23 13:17:58 OK 20260923120000_add_pushes.sql (15.93ms)11462026/09/23 13:17:58 goose: successfully migrated database to version: 2026092312000011472026/09/23 13:17:58 OK 1_commit_pending_closure.sql (2.18ms)11482026/09/23 13:17:58 OK 2_object_stats_trigger.sql (535.5µs)11492026/09/23 13:17:58 OK 3_commit_push.sql (384.67µs)11502026/09/23 13:17:58 goose: up to current file version: 311512026-09-23 13:17:58.631 UTC [59618] ERROR: relation "goose_db_version" does not exist at character 3611522026-09-23 13:17:58.631 UTC [59618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1153--- PASS: TestReadProxyNarStreaming (2.46s)1154=== CONT TestServerTLSConfig1155=== RUN TestServerTLSConfig/no_client_CA1156=== PAUSE TestServerTLSConfig/no_client_CA1157=== RUN TestServerTLSConfig/missing_CA_file1158=== PAUSE TestServerTLSConfig/missing_CA_file1159=== RUN TestServerTLSConfig/not_a_PEM_file1160=== PAUSE TestServerTLSConfig/not_a_PEM_file1161=== CONT TestService_NativeMTLS11622026/09/23 13:17:58 OK 20241026095416_initial_model.sql (90.96ms)11632026/09/23 13:17:58 OK 20251210153512_drop_unused_gin_index.sql (11.22ms)11642026/09/23 13:17:58 OK 20251218171726_add_pins.sql (20.32ms)11652026/09/23 13:17:58 OK 20260628120000_add_object_size_and_stats.sql (33.7ms)1166--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.26s)1167=== CONT TestMetricsInventory11682026/09/23 13:17:58 OK 20260905000000_add_claims.sql (52.15ms)11692026-09-23 13:17:58.964 UTC [59622] ERROR: relation "goose_db_version" does not exist at character 3611702026-09-23 13:17:58.964 UTC [59622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026/09/23 13:17:58 OK 20260920000000_drop_claims.sql (22.95ms)11722026/09/23 13:17:58 OK 20260923120000_add_pushes.sql (21.84ms)11732026/09/23 13:17:58 goose: successfully migrated database to version: 2026092312000011742026/09/23 13:17:58 OK 1_commit_pending_closure.sql (2.79ms)11752026/09/23 13:17:58 OK 2_object_stats_trigger.sql (782.21µs)11762026/09/23 13:17:58 OK 3_commit_push.sql (433.13µs)11772026/09/23 13:17:58 goose: up to current file version: 311782026-09-23 13:17:59.092 UTC [59624] ERROR: relation "goose_db_version" does not exist at character 3611792026-09-23 13:17:59.092 UTC [59624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11802026/09/23 13:17:59 OK 20241026095416_initial_model.sql (101.33ms)11812026/09/23 13:17:59 OK 20251210153512_drop_unused_gin_index.sql (9.69ms)11822026/09/23 13:17:59 OK 20251218171726_add_pins.sql (8.32ms)1183--- PASS: TestReadProxyNarinfo (2.20s)1184=== CONT TestNARDeduplicationMetadataUploadBug11852026/09/23 13:17:59 OK 20260628120000_add_object_size_and_stats.sql (35.17ms)11862026/09/23 13:17:59 OK 20260905000000_add_claims.sql (33.94ms)11872026/09/23 13:17:59 OK 20260920000000_drop_claims.sql (28.76ms)11882026/09/23 13:17:59 OK 20260923120000_add_pushes.sql (9.26ms)11892026/09/23 13:17:59 goose: successfully migrated database to version: 2026092312000011902026/09/23 13:17:59 OK 1_commit_pending_closure.sql (2.67ms)11912026/09/23 13:17:59 OK 2_object_stats_trigger.sql (618.08µs)11922026/09/23 13:17:59 OK 3_commit_push.sql (428.79µs)11932026/09/23 13:17:59 goose: up to current file version: 311942026/09/23 13:17:59 OK 20241026095416_initial_model.sql (113.6ms)11952026/09/23 13:17:59 OK 20251210153512_drop_unused_gin_index.sql (7.42ms)11962026/09/23 13:17:59 OK 20251218171726_add_pins.sql (16.4ms)11972026-09-23 13:17:59.277 UTC [59627] ERROR: relation "goose_db_version" does not exist at character 3611982026-09-23 13:17:59.277 UTC [59627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11992026/09/23 13:17:59 OK 20260628120000_add_object_size_and_stats.sql (69.82ms)12002026/09/23 13:17:59 INFO Starting HTTP server address=/nix/var/nix/builds/nix-59446-2641137695/TestProxyHeadersOnlyTrustedOnSocket853729295/001/proxy.sock12012026/09/23 13:17:59 INFO Starting HTTP server address=127.0.0.1:5810812022026/09/23 13:17:59 OK 20260905000000_add_claims.sql (35.76ms)12032026/09/23 13:17:59 WARN mTLS auth: subject not in bound subjects subject="CN=someone"12042026/09/23 13:17:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1205--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.12s)1206=== CONT TestCreatePendingClosureRejectsOversizedNAR12072026/09/23 13:17:59 INFO Received uploads request method=POST path=/api/pending_closures1208--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1209=== CONT TestCacheConfigHandlerMaxNarSize1210--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1211=== CONT TestGenerateLandingPage1212--- PASS: TestGenerateLandingPage (0.00s)1213=== CONT TestService_readinessHandler12142026/09/23 13:17:59 OK 20260920000000_drop_claims.sql (44.84ms)12152026/09/23 13:17:59 OK 20260923120000_add_pushes.sql (13.4ms)12162026/09/23 13:17:59 goose: successfully migrated database to version: 2026092312000012172026/09/23 13:17:59 OK 1_commit_pending_closure.sql (2.18ms)12182026/09/23 13:17:59 OK 2_object_stats_trigger.sql (550.92µs)12192026/09/23 13:17:59 OK 3_commit_push.sql (430.38µs)12202026/09/23 13:17:59 goose: up to current file version: 312212026-09-23 13:17:59.495 UTC [59630] ERROR: relation "goose_db_version" does not exist at character 3612222026-09-23 13:17:59.495 UTC [59630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12232026/09/23 13:17:59 OK 20241026095416_initial_model.sql (152.58ms)12242026/09/23 13:17:59 OK 20251210153512_drop_unused_gin_index.sql (2.91ms)12252026/09/23 13:17:59 OK 20251218171726_add_pins.sql (11.41ms)12262026-09-23 13:17:59.525 UTC [59631] ERROR: relation "goose_db_version" does not exist at character 3612272026-09-23 13:17:59.525 UTC [59631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12282026/09/23 13:17:59 OK 20260628120000_add_object_size_and_stats.sql (25.75ms)12292026/09/23 13:17:59 OK 20260905000000_add_claims.sql (19.23ms)12302026/09/23 13:17:59 OK 20260920000000_drop_claims.sql (21.17ms)12312026/09/23 13:17:59 OK 20260923120000_add_pushes.sql (17.48ms)12322026/09/23 13:17:59 goose: successfully migrated database to version: 2026092312000012332026/09/23 13:17:59 OK 1_commit_pending_closure.sql (3.14ms)12342026/09/23 13:17:59 OK 2_object_stats_trigger.sql (616.88µs)12352026/09/23 13:17:59 OK 3_commit_push.sql (500.29µs)12362026/09/23 13:17:59 goose: up to current file version: 312372026/09/23 13:17:59 OK 20241026095416_initial_model.sql (112.98ms)12382026/09/23 13:17:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12392026/09/23 13:17:59 WARN Refused reserved pin name=worker-x86_64-linux12402026/09/23 13:17:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12412026/09/23 13:17:59 INFO Received create pin request method=POST path=/api/pins/my-app12422026/09/23 13:17:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12432026/09/23 13:17:59 OK 20251210153512_drop_unused_gin_index.sql (14.15ms)1244--- PASS: TestCreatePin_ReservedPins (2.12s)1245=== CONT TestService_healthCheckHandler12462026/09/23 13:17:59 OK 20251218171726_add_pins.sql (29.1ms)12472026/09/23 13:17:59 OK 20260628120000_add_object_size_and_stats.sql (32.54ms)12482026/09/23 13:17:59 OK 20241026095416_initial_model.sql (174.07ms)12492026/09/23 13:17:59 OK 20251210153512_drop_unused_gin_index.sql (22.02ms)12502026/09/23 13:17:59 OK 20260905000000_add_claims.sql (49.27ms)12512026/09/23 13:17:59 OK 20251218171726_add_pins.sql (9.35ms)12522026/09/23 13:17:59 OK 20260920000000_drop_claims.sql (24.25ms)12532026/09/23 13:17:59 OK 20260628120000_add_object_size_and_stats.sql (31.5ms)12542026/09/23 13:17:59 OK 20260923120000_add_pushes.sql (26.45ms)12552026/09/23 13:17:59 goose: successfully migrated database to version: 2026092312000012562026/09/23 13:17:59 OK 1_commit_pending_closure.sql (3.12ms)12572026/09/23 13:17:59 OK 2_object_stats_trigger.sql (772.04µs)12582026/09/23 13:17:59 OK 3_commit_push.sql (648.33µs)12592026/09/23 13:17:59 goose: up to current file version: 312602026-09-23 13:17:59.822 UTC [59634] ERROR: relation "goose_db_version" does not exist at character 3612612026-09-23 13:17:59.822 UTC [59634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12622026/09/23 13:17:59 OK 20260905000000_add_claims.sql (45.94ms)12632026/09/23 13:17:59 OK 20260920000000_drop_claims.sql (38.31ms)12642026/09/23 13:17:59 OK 20260923120000_add_pushes.sql (21.08ms)12652026/09/23 13:17:59 goose: successfully migrated database to version: 2026092312000012662026/09/23 13:17:59 OK 1_commit_pending_closure.sql (4.09ms)12672026/09/23 13:17:59 OK 2_object_stats_trigger.sql (804.5µs)12682026/09/23 13:17:59 OK 3_commit_push.sql (623.67µs)12692026/09/23 13:17:59 goose: up to current file version: 312702026/09/23 13:18:00 OK 20241026095416_initial_model.sql (210.91ms)1271--- PASS: TestResurrectedObjectNotDeleted (2.34s)1272=== CONT TestGracefulShutdownDrainsInflight12732026/09/23 13:18:00 INFO Starting HTTP server address=127.0.0.1:5811412742026/09/23 13:18:00 INFO Shutdown signal received, draining in-flight requests timeout=10s12752026/09/23 13:18:00 OK 20251210153512_drop_unused_gin_index.sql (15ms)12762026/09/23 13:18:00 OK 20251218171726_add_pins.sql (39.53ms)1277--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1278=== CONT TestUploadHandlersRejectOversizedBody12792026/09/23 13:18:00 OK 20260628120000_add_object_size_and_stats.sql (54.85ms)1280=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1281=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1282=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1283=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1284=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1285=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1286=== CONT TestCompleteMultipartUnregistered12872026/09/23 13:18:00 OK 20260905000000_add_claims.sql (46.63ms)12882026/09/23 13:18:00 OK 20260920000000_drop_claims.sql (31.61ms)12892026/09/23 13:18:00 OK 20260923120000_add_pushes.sql (16.72ms)12902026/09/23 13:18:00 goose: successfully migrated database to version: 2026092312000012912026/09/23 13:18:00 OK 1_commit_pending_closure.sql (1.72ms)12922026/09/23 13:18:00 OK 2_object_stats_trigger.sql (422.71µs)12932026/09/23 13:18:00 OK 3_commit_push.sql (360.79µs)12942026/09/23 13:18:00 goose: up to current file version: 312952026-09-23 13:18:00.329 UTC [59640] ERROR: relation "goose_db_version" does not exist at character 3612962026-09-23 13:18:00.329 UTC [59640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12972026/09/23 13:18:00 OK 20241026095416_initial_model.sql (256.96ms)12982026/09/23 13:18:00 OK 20251210153512_drop_unused_gin_index.sql (16.53ms)12992026/09/23 13:18:00 OK 20251218171726_add_pins.sql (58.52ms)13002026/09/23 13:18:00 OK 20260628120000_add_object_size_and_stats.sql (61.67ms)13012026/09/23 13:18:00 OK 20260905000000_add_claims.sql (64.29ms)13022026/09/23 13:18:00 OK 20260920000000_drop_claims.sql (36.84ms)13032026/09/23 13:18:00 OK 20260923120000_add_pushes.sql (24.22ms)13042026/09/23 13:18:00 goose: successfully migrated database to version: 2026092312000013052026/09/23 13:18:00 OK 1_commit_pending_closure.sql (4.17ms)13062026/09/23 13:18:00 OK 2_object_stats_trigger.sql (952.29µs)13072026/09/23 13:18:00 OK 3_commit_push.sql (553.71µs)13082026/09/23 13:18:00 goose: up to current file version: 313092026-09-23 13:18:01.019 UTC [59641] ERROR: relation "goose_db_version" does not exist at character 3613102026-09-23 13:18:01.019 UTC [59641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1311--- PASS: TestObjectStatsTrigger (2.84s)1312=== CONT TestService_verifyS3Integrity13132026/09/23 13:18:01 OK 20241026095416_initial_model.sql (257.3ms)13142026/09/23 13:18:01 OK 20251210153512_drop_unused_gin_index.sql (25.26ms)13152026/09/23 13:18:01 INFO Received uploads request method=POST path=/api/pending_closures13162026-09-23 13:18:01.422 UTC [59644] ERROR: relation "goose_db_version" does not exist at character 3613172026-09-23 13:18:01.422 UTC [59644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13182026/09/23 13:18:01 OK 20251218171726_add_pins.sql (51.41ms)13192026/09/23 13:18:01 OK 20260628120000_add_object_size_and_stats.sql (52.02ms)13202026/09/23 13:18:01 OK 20260905000000_add_claims.sql (78.66ms)1321=== NAME TestOrphanedObjectsGC1322 orphaned_objects_gc_test.go:290: GC Test Summary:1323 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1324 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1325 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1326 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1327 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1328--- PASS: TestOrphanedObjectsGC (3.38s)1329=== CONT TestService_createPendingClosureHandler13302026/09/23 13:18:01 INFO Received cleanup request method=DELETE path=/api/pending_closures13312026/09/23 13:18:01 INFO Aborted multipart uploads count=11332--- PASS: TestMultipartCleanup (3.17s)1333=== CONT TestService_cleanupPendingClosuresHandler13342026/09/23 13:18:01 OK 20260920000000_drop_claims.sql (85.5ms)13352026/09/23 13:18:01 OK 20260923120000_add_pushes.sql (24.32ms)13362026/09/23 13:18:01 goose: successfully migrated database to version: 2026092312000013372026/09/23 13:18:01 OK 1_commit_pending_closure.sql (2.01ms)13382026/09/23 13:18:01 OK 2_object_stats_trigger.sql (455.08µs)13392026/09/23 13:18:01 OK 3_commit_push.sql (366.08µs)13402026/09/23 13:18:01 goose: up to current file version: 313412026/09/23 13:18:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13422026/09/23 13:18:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1343--- PASS: TestService_NativeMTLS (3.13s)1344=== CONT TestGCTaskStore_StartNew1345--- PASS: TestGCTaskStore_StartNew (0.00s)1346=== CONT TestGCTaskStore_PhaseUpdates1347--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1348=== CONT TestGCTaskStore_CompletedAllowsNewTask1349--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1350=== CONT TestPinProtectsFromGC13512026/09/23 13:18:01 OK 20241026095416_initial_model.sql (306.11ms)13522026/09/23 13:18:01 OK 20251210153512_drop_unused_gin_index.sql (14.3ms)13532026/09/23 13:18:01 OK 20251218171726_add_pins.sql (51.32ms)13542026/09/23 13:18:01 OK 20260628120000_add_object_size_and_stats.sql (39.86ms)13552026-09-23 13:18:01.936 UTC [59651] ERROR: relation "goose_db_version" does not exist at character 3613562026-09-23 13:18:01.936 UTC [59651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13572026/09/23 13:18:02 OK 20260905000000_add_claims.sql (89.36ms)13582026/09/23 13:18:02 OK 20260920000000_drop_claims.sql (43.61ms)13592026/09/23 13:18:02 OK 20260923120000_add_pushes.sql (18.99ms)13602026/09/23 13:18:02 goose: successfully migrated database to version: 2026092312000013612026/09/23 13:18:02 OK 1_commit_pending_closure.sql (4.7ms)13622026/09/23 13:18:02 OK 2_object_stats_trigger.sql (831.63µs)13632026/09/23 13:18:02 OK 3_commit_push.sql (640.83µs)13642026/09/23 13:18:02 goose: up to current file version: 313652026/09/23 13:18:02 OK 20241026095416_initial_model.sql (225.78ms)13662026/09/23 13:18:02 OK 20251210153512_drop_unused_gin_index.sql (15.96ms)1367--- PASS: TestMetricsInventory (3.36s)1368=== CONT TestGCTaskStore_GetReturnsLatest1369--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1370=== CONT TestGCTaskStore_GetEmpty1371--- PASS: TestGCTaskStore_GetEmpty (0.00s)1372=== CONT TestGCMetrics13732026/09/23 13:18:02 OK 20251218171726_add_pins.sql (33.61ms)13742026/09/23 13:18:02 OK 20260628120000_add_object_size_and_stats.sql (46.26ms)13752026-09-23 13:18:02.442 UTC [59654] ERROR: relation "goose_db_version" does not exist at character 3613762026-09-23 13:18:02.442 UTC [59654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13772026/09/23 13:18:02 OK 20260905000000_add_claims.sql (100.75ms)13782026/09/23 13:18:02 OK 20260920000000_drop_claims.sql (69.99ms)13792026/09/23 13:18:02 OK 20260923120000_add_pushes.sql (65.51ms)13802026/09/23 13:18:02 goose: successfully migrated database to version: 2026092312000013812026/09/23 13:18:02 OK 1_commit_pending_closure.sql (6.41ms)13822026/09/23 13:18:02 OK 2_object_stats_trigger.sql (2.75ms)13832026/09/23 13:18:02 OK 3_commit_push.sql (1.4ms)13842026/09/23 13:18:02 goose: up to current file version: 313852026/09/23 13:18:02 OK 20241026095416_initial_model.sql (176.62ms)13862026/09/23 13:18:02 OK 20251210153512_drop_unused_gin_index.sql (19.36ms)13872026/09/23 13:18:02 OK 20251218171726_add_pins.sql (51.58ms)13882026/09/23 13:18:02 OK 20260628120000_add_object_size_and_stats.sql (57.76ms)1389=== NAME TestNARDeduplicationMetadataUploadBug1390 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-59446-2641137695/TestNARDeduplicationMetadataUploadBug813730243/001/store/lzs0dcc9g6i6s6hm7xgc1chknfm75pnr-file1.txt13912026/09/23 13:18:02 OK 20260905000000_add_claims.sql (97.47ms)13922026/09/23 13:18:02 WARN readiness check failed error="closed pool"1393--- PASS: TestService_readinessHandler (3.52s)13942026-09-23 13:18:02.918 UTC [59657] ERROR: relation "goose_db_version" does not exist at character 3613952026-09-23 13:18:02.918 UTC [59657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1396=== CONT TestGCTaskStore_ConflictDifferentParams1397--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1398=== CONT TestGCBugBareHashReferences13992026/09/23 13:18:02 OK 20260920000000_drop_claims.sql (21.59ms)14002026/09/23 13:18:02 OK 20260923120000_add_pushes.sql (21.77ms)14012026/09/23 13:18:02 goose: successfully migrated database to version: 2026092312000014022026/09/23 13:18:02 OK 1_commit_pending_closure.sql (2.61ms)14032026/09/23 13:18:02 OK 2_object_stats_trigger.sql (327.38µs)14042026/09/23 13:18:02 OK 3_commit_push.sql (226.42µs)14052026/09/23 13:18:02 goose: up to current file version: 314062026/09/23 13:18:03 INFO Received uploads request method=POST path=/api/pending_closures14072026/09/23 13:18:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14082026/09/23 13:18:03 INFO Uploading lzs0dcc9g6i6s6hm7xgc1chknfm75pnr-file1.txt (160B)14092026/09/23 13:18:03 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14102026/09/23 13:18:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14112026/09/23 13:18:03 WARN Failed to register uploaded object key=lzs0dcc9g6i6s6hm7xgc1chknfm75pnr.ls error="server returned 404: 404 page not found\n"14122026/09/23 13:18:03 INFO Signed narinfos id=1 count=114132026/09/23 13:18:03 INFO Uploading 1 narinfos14142026/09/23 13:18:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14152026/09/23 13:18:03 WARN Failed to register uploaded object key=lzs0dcc9g6i6s6hm7xgc1chknfm75pnr.narinfo error="server returned 404: 404 page not found\n"14162026/09/23 13:18:03 INFO Completed upload id=114172026/09/23 13:18:03 INFO Upload complete. (174ms)1418=== NAME TestNARDeduplicationMetadataUploadBug1419 metadata_upload_test.go:54: Retrieved narinfo from S3:1420 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestNARDeduplicationMetadataUploadBug813730243/001/store/lzs0dcc9g6i6s6hm7xgc1chknfm75pnr-file1.txt1421 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1422 Compression: zstd1423 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1424 NarSize: 1601425 References: 1426 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1427 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1428 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1429 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14302026/09/23 13:18:03 OK 20241026095416_initial_model.sql (189.63ms)14312026/09/23 13:18:03 OK 20251210153512_drop_unused_gin_index.sql (18.05ms)14322026/09/23 13:18:03 OK 20251218171726_add_pins.sql (31.17ms)1433--- PASS: TestService_healthCheckHandler (3.59s)1434=== CONT TestGCTaskStore_DeduplicateSameParams1435--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1436=== CONT TestLeadEndsOnShutdown14372026/09/23 13:18:03 OK 20260628120000_add_object_size_and_stats.sql (27.65ms)1438=== NAME TestNARDeduplicationMetadataUploadBug1439 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-59446-2641137695/TestNARDeduplicationMetadataUploadBug813730243/001/store/lkljqs11z3wcw4hdpl44q74r5x691qxj-file2.txt14402026/09/23 13:18:03 OK 20260905000000_add_claims.sql (15.7ms)14412026/09/23 13:18:03 OK 20260920000000_drop_claims.sql (13.25ms)14422026/09/23 13:18:03 OK 20260923120000_add_pushes.sql (7.68ms)14432026/09/23 13:18:03 goose: successfully migrated database to version: 2026092312000014442026/09/23 13:18:03 OK 1_commit_pending_closure.sql (1.06ms)14452026/09/23 13:18:03 OK 2_object_stats_trigger.sql (255.08µs)14462026/09/23 13:18:03 OK 3_commit_push.sql (197.5µs)14472026/09/23 13:18:03 goose: up to current file version: 314482026/09/23 13:18:03 INFO Received uploads request method=POST path=/api/pending_closures14492026/09/23 13:18:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14502026/09/23 13:18:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14512026/09/23 13:18:03 INFO Signed narinfos id=2 count=114522026/09/23 13:18:03 INFO Uploading 1 narinfos14532026/09/23 13:18:03 WARN Failed to register uploaded object key=lkljqs11z3wcw4hdpl44q74r5x691qxj.ls error="server returned 404: 404 page not found\n"14542026/09/23 13:18:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14552026/09/23 13:18:03 WARN Failed to register uploaded object key=lkljqs11z3wcw4hdpl44q74r5x691qxj.narinfo error="server returned 404: 404 page not found\n"14562026/09/23 13:18:03 INFO Completed upload id=214572026/09/23 13:18:03 INFO Upload complete. (73ms)1458 metadata_upload_test.go:76: Retrieved narinfo from S3:1459 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestNARDeduplicationMetadataUploadBug813730243/001/store/lkljqs11z3wcw4hdpl44q74r5x691qxj-file2.txt1460 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1461 Compression: zstd1462 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1463 NarSize: 1601464 References: 1465 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1466 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1467 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1468 {"version":1,"root":{"type":"regular","size":44}}14692026-09-23 13:18:03.424 UTC [59672] ERROR: relation "goose_db_version" does not exist at character 3614702026-09-23 13:18:03.424 UTC [59672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1471--- PASS: TestNARDeduplicationMetadataUploadBug (4.29s)1472=== CONT TestProxyWriteTimeout1473=== RUN TestProxyWriteTimeout/narinfo1474=== PAUSE TestProxyWriteTimeout/narinfo1475=== RUN TestProxyWriteTimeout/1_GiB_nar1476=== PAUSE TestProxyWriteTimeout/1_GiB_nar1477=== RUN TestProxyWriteTimeout/10_GiB_nar1478=== PAUSE TestProxyWriteTimeout/10_GiB_nar1479=== RUN TestProxyWriteTimeout/unknown_size1480=== PAUSE TestProxyWriteTimeout/unknown_size1481=== CONT TestUploadHandlersRejectInvalidKeys1482=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1483=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1484=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1485=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1486=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1487=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1488=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1489=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1490=== CONT TestIsValidUploadKey1491=== RUN TestIsValidUploadKey/narinfo1492=== PAUSE TestIsValidUploadKey/narinfo1493=== RUN TestIsValidUploadKey/nar_zst1494=== PAUSE TestIsValidUploadKey/nar_zst1495=== RUN TestIsValidUploadKey/nar_xz1496=== PAUSE TestIsValidUploadKey/nar_xz1497=== RUN TestIsValidUploadKey/nar_plain1498=== PAUSE TestIsValidUploadKey/nar_plain1499=== RUN TestIsValidUploadKey/listing1500=== PAUSE TestIsValidUploadKey/listing1501=== RUN TestIsValidUploadKey/build_log1502=== PAUSE TestIsValidUploadKey/build_log1503=== RUN TestIsValidUploadKey/build_log_home-manager_file1504=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1505=== RUN TestIsValidUploadKey/build_log_plus_in_name1506=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1507=== RUN TestIsValidUploadKey/build_log_question_mark1508=== PAUSE TestIsValidUploadKey/build_log_question_mark1509=== RUN TestIsValidUploadKey/build_log_equals1510=== PAUSE TestIsValidUploadKey/build_log_equals1511=== RUN TestIsValidUploadKey/realisation1512=== PAUSE TestIsValidUploadKey/realisation1513=== RUN TestIsValidUploadKey/realisation_plus_in_output1514=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1515=== RUN TestIsValidUploadKey/nix-cache-info1516=== PAUSE TestIsValidUploadKey/nix-cache-info1517=== RUN TestIsValidUploadKey/index.html1518=== PAUSE TestIsValidUploadKey/index.html1519=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1520=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1521=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1522=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1523=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1524=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1525=== RUN TestIsValidUploadKey/traversal1526=== PAUSE TestIsValidUploadKey/traversal1527=== RUN TestIsValidUploadKey/traversal_nar1528=== PAUSE TestIsValidUploadKey/traversal_nar1529=== RUN TestIsValidUploadKey/absolute1530=== PAUSE TestIsValidUploadKey/absolute1531=== RUN TestIsValidUploadKey/empty_key1532=== PAUSE TestIsValidUploadKey/empty_key1533=== RUN TestIsValidUploadKey/unknown_type1534=== PAUSE TestIsValidUploadKey/unknown_type1535=== CONT TestLeadElectsOneAndHandsOver15362026/09/23 13:18:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15372026/09/23 13:18:03 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1538--- PASS: TestCompleteMultipartUnregistered (3.30s)1539=== CONT TestClientPushesUseOnePush15402026/09/23 13:18:03 OK 20241026095416_initial_model.sql (90.6ms)15412026/09/23 13:18:03 OK 20251210153512_drop_unused_gin_index.sql (9.67ms)15422026/09/23 13:18:03 OK 20251218171726_add_pins.sql (7.4ms)15432026/09/23 13:18:03 OK 20260628120000_add_object_size_and_stats.sql (15.43ms)15442026/09/23 13:18:03 OK 20260905000000_add_claims.sql (19.08ms)15452026/09/23 13:18:03 OK 20260920000000_drop_claims.sql (17.26ms)15462026-09-23 13:18:03.635 UTC [59677] ERROR: relation "goose_db_version" does not exist at character 3615472026-09-23 13:18:03.635 UTC [59677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15482026-09-23 13:18:03.635 UTC [59678] ERROR: relation "goose_db_version" does not exist at character 3615492026-09-23 13:18:03.635 UTC [59678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15502026/09/23 13:18:03 OK 20260923120000_add_pushes.sql (8.07ms)15512026/09/23 13:18:03 goose: successfully migrated database to version: 2026092312000015522026/09/23 13:18:03 OK 1_commit_pending_closure.sql (1.39ms)15532026/09/23 13:18:03 OK 2_object_stats_trigger.sql (308.54µs)15542026/09/23 13:18:03 OK 3_commit_push.sql (261.5µs)15552026/09/23 13:18:03 goose: up to current file version: 315562026-09-23 13:18:03.750 UTC [59679] ERROR: relation "goose_db_version" does not exist at character 3615572026-09-23 13:18:03.750 UTC [59679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15582026/09/23 13:18:03 OK 20241026095416_initial_model.sql (144.73ms)15592026/09/23 13:18:03 OK 20241026095416_initial_model.sql (141.52ms)15602026/09/23 13:18:03 OK 20251210153512_drop_unused_gin_index.sql (11.47ms)15612026/09/23 13:18:03 OK 20251210153512_drop_unused_gin_index.sql (13.71ms)15622026/09/23 13:18:03 OK 20251218171726_add_pins.sql (18.61ms)15632026/09/23 13:18:03 OK 20251218171726_add_pins.sql (11.24ms)15642026/09/23 13:18:03 OK 20260628120000_add_object_size_and_stats.sql (42.22ms)15652026/09/23 13:18:03 INFO Received uploads request method=POST path=/api/pending_closures15662026/09/23 13:18:03 OK 20260628120000_add_object_size_and_stats.sql (49.27ms)15672026/09/23 13:18:03 OK 20260905000000_add_claims.sql (22.58ms)15682026/09/23 13:18:03 OK 20260905000000_add_claims.sql (42.41ms)15692026/09/23 13:18:03 OK 20241026095416_initial_model.sql (162.96ms)15702026/09/23 13:18:03 OK 20260920000000_drop_claims.sql (50.21ms)15712026/09/23 13:18:03 OK 20260920000000_drop_claims.sql (24.83ms)15722026/09/23 13:18:03 OK 20251210153512_drop_unused_gin_index.sql (7.86ms)15732026/09/23 13:18:03 OK 20260923120000_add_pushes.sql (7.81ms)15742026/09/23 13:18:03 goose: successfully migrated database to version: 2026092312000015752026/09/23 13:18:03 OK 20260923120000_add_pushes.sql (6.89ms)15762026/09/23 13:18:03 goose: successfully migrated database to version: 2026092312000015772026/09/23 13:18:03 OK 1_commit_pending_closure.sql (4.02ms)15782026/09/23 13:18:03 OK 1_commit_pending_closure.sql (4.44ms)15792026/09/23 13:18:03 OK 2_object_stats_trigger.sql (869.67µs)15802026/09/23 13:18:03 OK 2_object_stats_trigger.sql (891.25µs)15812026/09/23 13:18:03 OK 3_commit_push.sql (634.38µs)15822026/09/23 13:18:03 goose: up to current file version: 315832026/09/23 13:18:03 OK 3_commit_push.sql (587.63µs)15842026/09/23 13:18:03 goose: up to current file version: 315852026/09/23 13:18:04 OK 20251218171726_add_pins.sql (28.05ms)15862026/09/23 13:18:04 OK 20260628120000_add_object_size_and_stats.sql (34.42ms)15872026/09/23 13:18:04 OK 20260905000000_add_claims.sql (84.02ms)15882026/09/23 13:18:04 OK 20260920000000_drop_claims.sql (31.1ms)15892026/09/23 13:18:04 OK 20260923120000_add_pushes.sql (31.4ms)15902026/09/23 13:18:04 goose: successfully migrated database to version: 2026092312000015912026/09/23 13:18:04 OK 1_commit_pending_closure.sql (3.16ms)15922026/09/23 13:18:04 OK 2_object_stats_trigger.sql (818.92µs)15932026/09/23 13:18:04 OK 3_commit_push.sql (419.17µs)15942026/09/23 13:18:04 goose: up to current file version: 315952026-09-23 13:18:04.240 UTC [59680] ERROR: relation "goose_db_version" does not exist at character 3615962026-09-23 13:18:04.240 UTC [59680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15972026/09/23 13:18:04 INFO Received uploads request method=POST path=/api/pending_closures15982026/09/23 13:18:04 INFO Received uploads request method=POST path=/api/pending_closures15992026/09/23 13:18:04 INFO Received uploads request method=POST path=/api/pending_closures16002026/09/23 13:18:04 OK 20241026095416_initial_model.sql (249.32ms)16012026/09/23 13:18:04 OK 20251210153512_drop_unused_gin_index.sql (20.77ms)16022026/09/23 13:18:04 OK 20251218171726_add_pins.sql (46.8ms)16032026/09/23 13:18:04 INFO Received cleanup request method=DELETE path=/api/pending_closures16042026/09/23 13:18:04 INFO Aborted multipart uploads count=016052026/09/23 13:18:04 OK 20260628120000_add_object_size_and_stats.sql (50.67ms)16062026/09/23 13:18:04 INFO Received uploads request method=POST path=/api/pending_closures16072026/09/23 13:18:04 OK 20260905000000_add_claims.sql (119.91ms)16082026/09/23 13:18:04 OK 20260920000000_drop_claims.sql (88.14ms)16092026/09/23 13:18:04 INFO Received cleanup request method=DELETE path=/api/pending_closures16102026/09/23 13:18:04 INFO Aborted multipart uploads count=116112026/09/23 13:18:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16122026/09/23 13:18:04 OK 20260923120000_add_pushes.sql (33.14ms)16132026/09/23 13:18:04 goose: successfully migrated database to version: 2026092312000016142026-09-23 13:18:04.935 UTC [59678] ERROR: Closure does not exist: id=116152026-09-23 13:18:04.935 UTC [59678] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE16162026-09-23 13:18:04.935 UTC [59678] STATEMENT: -- name: CommitPendingClosure :exec1617 SELECT commit_pending_closure($1::bigint)1618 1619--- PASS: TestService_cleanupPendingClosuresHandler (3.29s)1620=== CONT TestResolveDBConnectionString16212026/09/23 13:18:04 OK 1_commit_pending_closure.sql (3.36ms)16222026/09/23 13:18:04 OK 2_object_stats_trigger.sql (801.96µs)16232026/09/23 13:18:04 OK 3_commit_push.sql (410.92µs)16242026/09/23 13:18:04 goose: up to current file version: 31625=== RUN TestResolveDBConnectionString/flag_wins1626=== PAUSE TestResolveDBConnectionString/flag_wins1627=== RUN TestResolveDBConnectionString/file_when_flag_empty1628=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1629=== RUN TestResolveDBConnectionString/missing_file_is_an_error1630=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1631=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1632=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1633=== RUN TestResolveDBConnectionString/nothing_configured1634=== PAUSE TestResolveDBConnectionString/nothing_configured1635=== CONT TestClientFallsBackToClosures16362026-09-23 13:18:05.357 UTC [59684] ERROR: relation "goose_db_version" does not exist at character 3616372026-09-23 13:18:05.357 UTC [59684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16382026/09/23 13:18:05 INFO Aborted multipart uploads count=016392026/09/23 13:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period16402026/09/23 13:18: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=016412026/09/23 13:18:05 INFO Vacuumed table table=pending_closures16422026/09/23 13:18:05 INFO Vacuumed table table=pending_objects16432026/09/23 13:18:05 INFO Vacuumed table table=multipart_uploads16442026/09/23 13:18:05 INFO Vacuumed table table=closures16452026/09/23 13:18:05 INFO Vacuumed table table=objects1646--- PASS: TestGCMetrics (3.22s)1647=== CONT TestCacheStatsHandler1648=== NAME TestPinProtectsFromGC1649 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-59446-2641137695/TestPinProtectsFromGC2043268349/001/store/ffi8wf2hvdc25zfgl4gbd7c9jkn899az-pinned-file.txt1650 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-59446-2641137695/TestPinProtectsFromGC2043268349/001/store/1fp89bbmlvi8kd3pg38yv0n09av4j89q-unpinned-file.txt16512026-09-23 13:18:05.624 UTC [59691] ERROR: relation "goose_db_version" does not exist at character 3616522026-09-23 13:18:05.624 UTC [59691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16532026/09/23 13:18:05 OK 20241026095416_initial_model.sql (199.33ms)16542026/09/23 13:18:05 OK 20251210153512_drop_unused_gin_index.sql (7.08ms)16552026-09-23 13:18:05.655 UTC [59692] ERROR: relation "goose_db_version" does not exist at character 3616562026-09-23 13:18:05.655 UTC [59692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16572026/09/23 13:18:05 OK 20251218171726_add_pins.sql (27.63ms)16582026/09/23 13:18:05 INFO Received uploads request method=POST path=/api/pending_closures16592026/09/23 13:18:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16602026/09/23 13:18:05 OK 20260628120000_add_object_size_and_stats.sql (58.93ms)16612026/09/23 13:18:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16622026/09/23 13:18:05 INFO Uploading ffi8wf2hvdc25zfgl4gbd7c9jkn899az-pinned-file.txt (128B)16632026/09/23 13:18:05 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16642026/09/23 13:18:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16652026/09/23 13:18:05 INFO Signed narinfos id=1 count=116662026/09/23 13:18:05 WARN Failed to register uploaded object key=ffi8wf2hvdc25zfgl4gbd7c9jkn899az.ls error="server returned 404: 404 page not found\n"16672026/09/23 13:18:05 INFO Uploading 1 narinfos16682026/09/23 13:18:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16692026/09/23 13:18:05 WARN Failed to register uploaded object key=ffi8wf2hvdc25zfgl4gbd7c9jkn899az.narinfo error="server returned 404: 404 page not found\n"16702026/09/23 13:18:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjJhNWY1MmEtYjE4My00YmI5LTk2YmEtNjY3Nzc1ZjBiMjA2LmYxNzUwZDU2LTAyMmQtNDQ2MS04YzNiLWNjZTNkMzg2ZWIzZHgxNzkwMTY5NDgzOTIwMDgyMDAw parts=1016712026/09/23 13:18:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16722026/09/23 13:18:05 OK 20260905000000_add_claims.sql (45.28ms)16732026/09/23 13:18:05 INFO Completed upload id=116742026/09/23 13:18:05 INFO Received uploads request method=POST path=/api/pending_closures16752026/09/23 13:18:05 INFO Received uploads request method=POST path=/api/pending_closures16762026/09/23 13:18:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16772026/09/23 13:18:05 WARN Found objects in DB but missing from S3, will re-upload count=11678--- PASS: TestService_verifyS3Integrity (4.68s)1679=== CONT TestClientSharedPathCommittedMidPush16802026/09/23 13:18:05 INFO Completed upload id=116812026/09/23 13:18:05 INFO Upload complete. (144ms)16822026/09/23 13:18:05 OK 20260920000000_drop_claims.sql (14.65ms)16832026-09-23 13:18:05.796 UTC [59697] ERROR: relation "goose_db_version" does not exist at character 3616842026-09-23 13:18:05.796 UTC [59697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16852026/09/23 13:18:05 OK 20241026095416_initial_model.sql (129.48ms)16862026/09/23 13:18:05 OK 20260923120000_add_pushes.sql (14.01ms)16872026/09/23 13:18:05 goose: successfully migrated database to version: 2026092312000016882026/09/23 13:18:05 OK 1_commit_pending_closure.sql (1.29ms)16892026/09/23 13:18:05 OK 2_object_stats_trigger.sql (211.92µs)16902026/09/23 13:18:05 OK 3_commit_push.sql (191.08µs)16912026/09/23 13:18:05 goose: up to current file version: 316922026/09/23 13:18:05 OK 20251210153512_drop_unused_gin_index.sql (11.86ms)16932026/09/23 13:18:05 OK 20251218171726_add_pins.sql (33.08ms)16942026/09/23 13:18:05 OK 20241026095416_initial_model.sql (117.21ms)16952026/09/23 13:18:05 OK 20251210153512_drop_unused_gin_index.sql (10.25ms)16962026/09/23 13:18:05 OK 20260628120000_add_object_size_and_stats.sql (26.77ms)16972026/09/23 13:18:05 INFO Received uploads request method=POST path=/api/pending_closures16982026/09/23 13:18:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16992026/09/23 13:18:05 INFO Uploading 1fp89bbmlvi8kd3pg38yv0n09av4j89q-unpinned-file.txt (128B)17002026/09/23 13:18:05 OK 20251218171726_add_pins.sql (15.22ms)17012026/09/23 13:18:05 WARN Failed to register uploaded object key=1fp89bbmlvi8kd3pg38yv0n09av4j89q.ls error="server returned 404: 404 page not found\n"17022026/09/23 13:18:05 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17032026/09/23 13:18:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17042026/09/23 13:18:05 INFO Signed narinfos id=2 count=117052026/09/23 13:18:05 INFO Uploading 1 narinfos17062026/09/23 13:18:05 OK 20260628120000_add_object_size_and_stats.sql (36.07ms)17072026/09/23 13:18:05 OK 20260905000000_add_claims.sql (63.34ms)17082026/09/23 13:18:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17092026/09/23 13:18:05 WARN Failed to register uploaded object key=1fp89bbmlvi8kd3pg38yv0n09av4j89q.narinfo error="server returned 404: 404 page not found\n"17102026/09/23 13:18:05 INFO Completed upload id=217112026/09/23 13:18:05 INFO Upload complete. (112ms)17122026/09/23 13:18:05 INFO Received create pin request method=POST path=/api/pins/myapp17132026/09/23 13:18:05 OK 20260920000000_drop_claims.sql (44.86ms)17142026/09/23 13:18:05 OK 20260905000000_add_claims.sql (69.78ms)17152026/09/23 13:18:05 OK 20260923120000_add_pushes.sql (12.27ms)17162026/09/23 13:18:05 goose: successfully migrated database to version: 2026092312000017172026/09/23 13:18:06 OK 1_commit_pending_closure.sql (906.21µs)17182026/09/23 13:18:06 OK 2_object_stats_trigger.sql (252.88µs)17192026/09/23 13:18:06 OK 3_commit_push.sql (198µs)17202026/09/23 13:18:06 goose: up to current file version: 317212026/09/23 13:18:06 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-59446-2641137695/TestPinProtectsFromGC2043268349/001/store/ffi8wf2hvdc25zfgl4gbd7c9jkn899az-pinned-file.txt narinfo_key=ffi8wf2hvdc25zfgl4gbd7c9jkn899az.narinfo17222026/09/23 13:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17232026/09/23 13:18:06 OK 20260920000000_drop_claims.sql (16.42ms)17242026/09/23 13:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures17252026/09/23 13:18:06 INFO Garbage collection started17262026/09/23 13:18:06 INFO Aborted multipart uploads count=017272026/09/23 13:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period17282026/09/23 13:18:06 OK 20260923120000_add_pushes.sql (5.75ms)17292026/09/23 13:18:06 goose: successfully migrated database to version: 2026092312000017302026/09/23 13:18:06 OK 1_commit_pending_closure.sql (762.42µs)17312026/09/23 13:18:06 OK 2_object_stats_trigger.sql (190.67µs)17322026/09/23 13:18:06 OK 3_commit_push.sql (183.79µs)17332026/09/23 13:18:06 goose: up to current file version: 317342026/09/23 13:18:06 OK 20241026095416_initial_model.sql (192.34ms)17352026/09/23 13:18:06 OK 20251210153512_drop_unused_gin_index.sql (10.7ms)17362026/09/23 13:18:06 OK 20251218171726_add_pins.sql (14.68ms)17372026/09/23 13:18:06 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjJhNWY1MmEtYjE4My00YmI5LTk2YmEtNjY3Nzc1ZjBiMjA2LjAyN2UzY2FjLTU4NzctNGIzYi05NDEyLThkYjg5NmExZTlkOHgxNzkwMTY5NDg0MzM3NjIzMDAw parts=1017382026/09/23 13:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17392026/09/23 13:18:06 INFO Completed upload id=117402026/09/23 13:18:06 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017412026/09/23 13:18:06 INFO Received uploads request method=POST path=/api/pending_closures17422026/09/23 13:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures17432026/09/23 13:18:06 INFO Aborted multipart uploads count=017442026/09/23 13:18:06 OK 20260628120000_add_object_size_and_stats.sql (24.25ms)17452026/09/23 13:18:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=017462026/09/23 13:18:06 INFO Vacuumed table table=pending_closures17472026/09/23 13:18:06 INFO Vacuumed table table=pending_objects17482026/09/23 13:18:06 OK 20260905000000_add_claims.sql (40.02ms)17492026/09/23 13:18:06 INFO Vacuumed table table=multipart_uploads17502026/09/23 13:18:06 OK 20260920000000_drop_claims.sql (17.49ms)17512026/09/23 13:18:06 INFO Vacuumed table table=closures17522026/09/23 13:18:06 OK 20260923120000_add_pushes.sql (10.73ms)17532026/09/23 13:18:06 goose: successfully migrated database to version: 2026092312000017542026/09/23 13:18:06 OK 1_commit_pending_closure.sql (1.5ms)17552026/09/23 13:18:06 OK 2_object_stats_trigger.sql (314.79µs)17562026/09/23 13:18:06 OK 3_commit_push.sql (243.5µs)17572026/09/23 13:18:06 goose: up to current file version: 317582026/09/23 13:18:06 INFO Vacuumed table table=objects17592026/09/23 13:18:06 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001760--- PASS: TestService_createPendingClosureHandler (4.60s)1761=== CONT TestClientWithDependencies17622026/09/23 13:18:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=017632026/09/23 13:18:06 INFO Vacuumed table table=pending_closures17642026/09/23 13:18:06 INFO Vacuumed table table=pending_objects17652026/09/23 13:18:06 INFO Vacuumed table table=multipart_uploads17662026/09/23 13:18:06 INFO Vacuumed table table=closures17672026/09/23 13:18:06 INFO lead: acquired remote=192.0.2.1:123417682026/09/23 13:18:06 INFO lead: released remote=192.0.2.1:12341769--- PASS: TestLeadEndsOnShutdown (3.07s)1770=== CONT TestClientMultipleUploads17712026/09/23 13:18:06 INFO Vacuumed table table=objects1772--- PASS: TestGCBugBareHashReferences (3.40s)1773=== CONT TestService_AuthMiddleware_OIDC17742026/09/23 13:18:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58155/oidc1775=== NAME TestOrphanedObjectsGCStressTest1776 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17772026/09/23 13:18:06 INFO lead: acquired remote=192.0.2.1:12341778 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17792026/09/23 13:18:06 INFO lead: released remote=192.0.2.1:123417802026-09-23 13:18:06.689 UTC [59716] ERROR: relation "goose_db_version" does not exist at character 3617812026-09-23 13:18:06.689 UTC [59716] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17822026/09/23 13:18:06 INFO lead: acquired remote=192.0.2.1:123417832026/09/23 13:18:06 INFO lead: released remote=192.0.2.1:12341784--- PASS: TestLeadElectsOneAndHandsOver (3.30s)1785=== CONT TestCacheConfigHandler1786=== RUN TestCacheConfigHandler/full_config,_no_issuer1787=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1788=== RUN TestCacheConfigHandler/no_cache_url_configured1789=== PAUSE TestCacheConfigHandler/no_cache_url_configured1790=== RUN TestCacheConfigHandler/no_signing_keys1791=== PAUSE TestCacheConfigHandler/no_signing_keys1792=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1793=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1794=== CONT TestService_ReadScope_PublicByDefault17952026/09/23 13:18:06 OK 20241026095416_initial_model.sql (41.44ms)17962026/09/23 13:18:06 OK 20251210153512_drop_unused_gin_index.sql (563.88µs)17972026/09/23 13:18:06 OK 20251218171726_add_pins.sql (1.09ms)17982026-09-23 13:18:06.806 UTC [59722] ERROR: relation "goose_db_version" does not exist at character 3617992026-09-23 13:18:06.806 UTC [59722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18002026/09/23 13:18:06 OK 20260628120000_add_object_size_and_stats.sql (5.22ms)18012026/09/23 13:18:06 OK 20260905000000_add_claims.sql (19.34ms)18022026/09/23 13:18:06 OK 20260920000000_drop_claims.sql (2.22ms)18032026/09/23 13:18:06 OK 20260923120000_add_pushes.sql (1.12ms)18042026/09/23 13:18:06 goose: successfully migrated database to version: 2026092312000018052026/09/23 13:18:06 OK 1_commit_pending_closure.sql (1.77ms)18062026/09/23 13:18:06 OK 2_object_stats_trigger.sql (825.08µs)18072026/09/23 13:18:06 OK 3_commit_push.sql (396.46µs)18082026/09/23 13:18:06 goose: up to current file version: 318092026/09/23 13:18:06 OK 20241026095416_initial_model.sql (24.58ms)18102026/09/23 13:18:06 OK 20251210153512_drop_unused_gin_index.sql (409.13µs)18112026/09/23 13:18:06 OK 20251218171726_add_pins.sql (1ms)18122026/09/23 13:18:06 OK 20260628120000_add_object_size_and_stats.sql (20.22ms)18132026/09/23 13:18:06 OK 20260905000000_add_claims.sql (14.22ms)18142026/09/23 13:18:06 OK 20260920000000_drop_claims.sql (2.69ms)18152026/09/23 13:18:06 OK 20260923120000_add_pushes.sql (941.79µs)18162026/09/23 13:18:06 goose: successfully migrated database to version: 2026092312000018172026/09/23 13:18:06 OK 1_commit_pending_closure.sql (874.75µs)18182026/09/23 13:18:06 OK 2_object_stats_trigger.sql (197.21µs)18192026/09/23 13:18:06 OK 3_commit_push.sql (181.21µs)18202026/09/23 13:18:06 goose: up to current file version: 318212026-09-23 13:18:06.889 UTC [59726] ERROR: relation "goose_db_version" does not exist at character 3618222026-09-23 13:18:06.889 UTC [59726] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18232026/09/23 13:18:06 OK 20241026095416_initial_model.sql (66.64ms)18242026/09/23 13:18:06 OK 20251210153512_drop_unused_gin_index.sql (5.76ms)18252026/09/23 13:18:07 INFO Received uploads request method=POST path=/api/pending_closures18262026/09/23 13:18:07 OK 20251218171726_add_pins.sql (36.76ms)18272026/09/23 13:18:07 INFO Received uploads request method=POST path=/api/pending_closures18282026/09/23 13:18:07 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18292026/09/23 13:18:07 INFO Uploading vcy60anh3v44k3khs5i29g1vg6qmalkv-b (248B)18302026/09/23 13:18:07 INFO Uploading bc6i909z0g3a92rf3snq6w1avjfmy332-shared-dep (136B)18312026/09/23 13:18:07 OK 20260628120000_add_object_size_and_stats.sql (18.2ms)18322026/09/23 13:18:07 WARN Failed to register uploaded object key=nar/1x8qzwphv1gjasx5pi2apsxaj48hh90vgwz3rkffk2f6jyfhpm5k.nar.zst error="server returned 404: 404 page not found\n"18332026/09/23 13:18:07 WARN Failed to register uploaded object key=bc6i909z0g3a92rf3snq6w1avjfmy332.ls error="server returned 404: 404 page not found\n"18342026/09/23 13:18:07 WARN Failed to register uploaded object key=vcy60anh3v44k3khs5i29g1vg6qmalkv.ls error="server returned 404: 404 page not found\n"18352026/09/23 13:18:07 WARN Failed to register uploaded object key=pncc4p1z7s570h9fi4v8pxm2dls2m7yd.ls error="server returned 404: 404 page not found\n"18362026/09/23 13:18:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18372026/09/23 13:18:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18382026/09/23 13:18:07 INFO Signed narinfos id=1 count=218392026/09/23 13:18:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18402026/09/23 13:18:07 INFO Signed narinfos id=2 count=218412026/09/23 13:18:07 INFO Uploading 4 narinfos18422026/09/23 13:18:07 WARN Failed to register uploaded object key=pncc4p1z7s570h9fi4v8pxm2dls2m7yd.narinfo error="server returned 404: 404 page not found\n"18432026/09/23 13:18:07 WARN Failed to register uploaded object key=vcy60anh3v44k3khs5i29g1vg6qmalkv.narinfo error="server returned 404: 404 page not found\n"18442026/09/23 13:18:07 OK 20260905000000_add_claims.sql (41.65ms)18452026/09/23 13:18:07 WARN Failed to register uploaded object key=bc6i909z0g3a92rf3snq6w1avjfmy332.narinfo error="server returned 404: 404 page not found\n"18462026/09/23 13:18:07 OK 20260920000000_drop_claims.sql (28.56ms)18472026/09/23 13:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18482026/09/23 13:18:07 WARN Failed to register uploaded object key=bc6i909z0g3a92rf3snq6w1avjfmy332.narinfo error="server returned 404: 404 page not found\n"18492026/09/23 13:18:07 OK 20260923120000_add_pushes.sql (5.96ms)18502026/09/23 13:18:07 goose: successfully migrated database to version: 2026092312000018512026/09/23 13:18:07 OK 1_commit_pending_closure.sql (912.46µs)18522026/09/23 13:18:07 OK 2_object_stats_trigger.sql (237.42µs)18532026/09/23 13:18:07 OK 3_commit_push.sql (192.83µs)18542026/09/23 13:18:07 goose: up to current file version: 318552026/09/23 13:18:07 INFO Completed upload id=118562026/09/23 13:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18572026/09/23 13:18:07 INFO Completed upload id=218582026/09/23 13:18:07 INFO Upload complete. (173ms)1859=== NAME TestClientPushesUseOnePush1860 client_pushes_test.go:97: Retrieved narinfo from S3:1861 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientPushesUseOnePush4101128966/001/store/bc6i909z0g3a92rf3snq6w1avjfmy332-shared-dep1862 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1863 Compression: zstd1864 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821865 NarSize: 1361866 References: 1867 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1868 client_pushes_test.go:97: Retrieved narinfo from S3:1869 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientPushesUseOnePush4101128966/001/store/pncc4p1z7s570h9fi4v8pxm2dls2m7yd-a1870 URL: nar/1x8qzwphv1gjasx5pi2apsxaj48hh90vgwz3rkffk2f6jyfhpm5k.nar.zst1871 Compression: zstd1872 NarHash: sha256:1x8qzwphv1gjasx5pi2apsxaj48hh90vgwz3rkffk2f6jyfhpm5k1873 NarSize: 2481874 References: /nix/var/nix/builds/nix-59446-2641137695/TestClientPushesUseOnePush4101128966/001/store/bc6i909z0g3a92rf3snq6w1avjfmy332-shared-dep1875 CA: text:sha256:114l3agx12a08bj0p491razwlrz7wsrpf16d24c5b64g80159r3s1876 client_pushes_test.go:97: Retrieved narinfo from S3:1877 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientPushesUseOnePush4101128966/001/store/vcy60anh3v44k3khs5i29g1vg6qmalkv-b1878 URL: nar/1x8qzwphv1gjasx5pi2apsxaj48hh90vgwz3rkffk2f6jyfhpm5k.nar.zst1879 Compression: zstd1880 NarHash: sha256:1x8qzwphv1gjasx5pi2apsxaj48hh90vgwz3rkffk2f6jyfhpm5k1881 NarSize: 2481882 References: /nix/var/nix/builds/nix-59446-2641137695/TestClientPushesUseOnePush4101128966/001/store/bc6i909z0g3a92rf3snq6w1avjfmy332-shared-dep1883 CA: text:sha256:114l3agx12a08bj0p491razwlrz7wsrpf16d24c5b64g80159r3s1884 client_pushes_test.go:100: POST /api/pushes calls = 0, want 11885 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 01886--- FAIL: TestClientPushesUseOnePush (3.68s)1887=== CONT TestService_RequireScope_OIDC18882026/09/23 13:18:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58170/oidc1889--- PASS: TestCacheStatsHandler (1.77s)1890=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle18912026-09-23 13:18:07.336 UTC [59747] ERROR: relation "goose_db_version" does not exist at character 3618922026-09-23 13:18:07.336 UTC [59747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18932026/09/23 13:18:07 INFO Received uploads request method=POST path=/api/pending_closures18942026/09/23 13:18:07 INFO Received uploads request method=POST path=/api/pending_closures18952026/09/23 13:18:07 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18962026/09/23 13:18:07 INFO Uploading lc5kb3iyvwhsdnads009m6a2wwqcvbhh-a (248B)18972026/09/23 13:18:07 INFO Uploading rjdn056aybfvrjpgsws7bylbk1imav3a-shared-dep (136B)18982026-09-23 13:18:07.370 UTC [59750] ERROR: relation "goose_db_version" does not exist at character 3618992026-09-23 13:18:07.370 UTC [59750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19002026/09/23 13:18:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19012026/09/23 13:18:07 WARN Failed to register uploaded object key=lc5kb3iyvwhsdnads009m6a2wwqcvbhh.ls error="server returned 404: 404 page not found\n"19022026/09/23 13:18:07 WARN Failed to register uploaded object key=rjdn056aybfvrjpgsws7bylbk1imav3a.ls error="server returned 404: 404 page not found\n"19032026-09-23 13:18:07.386 UTC [59749] ERROR: relation "goose_db_version" does not exist at character 3619042026-09-23 13:18:07.386 UTC [59749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19052026/09/23 13:18:07 WARN Failed to register uploaded object key=bqjmfh7jp00ysbxgbjjl06ag2lqqn5ha.ls error="server returned 404: 404 page not found\n"19062026/09/23 13:18:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19072026/09/23 13:18:07 WARN Failed to register uploaded object key=nar/13hfzpjl6pds8vfdbj0mp2zbbq8m7jn1sf1j7444v3gzfvld14va.nar.zst error="server returned 404: 404 page not found\n"19082026/09/23 13:18:07 INFO Signed narinfos id=1 count=219092026/09/23 13:18:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19102026/09/23 13:18:07 INFO Signed narinfos id=2 count=219112026/09/23 13:18:07 INFO Uploading 4 narinfos19122026/09/23 13:18:07 WARN Failed to register uploaded object key=bqjmfh7jp00ysbxgbjjl06ag2lqqn5ha.narinfo error="server returned 404: 404 page not found\n"19132026/09/23 13:18:07 WARN Failed to register uploaded object key=rjdn056aybfvrjpgsws7bylbk1imav3a.narinfo error="server returned 404: 404 page not found\n"19142026/09/23 13:18:07 WARN Failed to register uploaded object key=lc5kb3iyvwhsdnads009m6a2wwqcvbhh.narinfo error="server returned 404: 404 page not found\n"19152026/09/23 13:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19162026/09/23 13:18:07 WARN Failed to register uploaded object key=rjdn056aybfvrjpgsws7bylbk1imav3a.narinfo error="server returned 404: 404 page not found\n"19172026/09/23 13:18:07 INFO Completed upload id=119182026/09/23 13:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19192026/09/23 13:18:07 INFO Completed upload id=219202026/09/23 13:18:07 INFO Upload complete. (135ms)1921=== NAME TestClientFallsBackToClosures1922 client_pushes_test.go:112: Retrieved narinfo from S3:1923 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientFallsBackToClosures4195823870/001/store/rjdn056aybfvrjpgsws7bylbk1imav3a-shared-dep1924 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1925 Compression: zstd1926 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821927 NarSize: 1361928 References: 1929 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1930 client_pushes_test.go:112: Retrieved narinfo from S3:1931 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientFallsBackToClosures4195823870/001/store/lc5kb3iyvwhsdnads009m6a2wwqcvbhh-a1932 URL: nar/13hfzpjl6pds8vfdbj0mp2zbbq8m7jn1sf1j7444v3gzfvld14va.nar.zst1933 Compression: zstd1934 NarHash: sha256:13hfzpjl6pds8vfdbj0mp2zbbq8m7jn1sf1j7444v3gzfvld14va1935 NarSize: 2481936 References: /nix/var/nix/builds/nix-59446-2641137695/TestClientFallsBackToClosures4195823870/001/store/rjdn056aybfvrjpgsws7bylbk1imav3a-shared-dep1937 CA: text:sha256:1r3ikp0ji87gzd5x54xvy3mxglkhdlbw94y1xjwvb6kf5i3ysiba1938 client_pushes_test.go:112: Retrieved narinfo from S3:1939 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientFallsBackToClosures4195823870/001/store/bqjmfh7jp00ysbxgbjjl06ag2lqqn5ha-b1940 URL: nar/13hfzpjl6pds8vfdbj0mp2zbbq8m7jn1sf1j7444v3gzfvld14va.nar.zst1941 Compression: zstd1942 NarHash: sha256:13hfzpjl6pds8vfdbj0mp2zbbq8m7jn1sf1j7444v3gzfvld14va1943 NarSize: 2481944 References: /nix/var/nix/builds/nix-59446-2641137695/TestClientFallsBackToClosures4195823870/001/store/rjdn056aybfvrjpgsws7bylbk1imav3a-shared-dep1945 CA: text:sha256:1r3ikp0ji87gzd5x54xvy3mxglkhdlbw94y1xjwvb6kf5i3ysiba19462026/09/23 13:18:07 OK 20241026095416_initial_model.sql (86.59ms)19472026/09/23 13:18:07 OK 20251210153512_drop_unused_gin_index.sql (7.92ms)1948--- PASS: TestClientFallsBackToClosures (2.52s)1949=== CONT TestSkippedUploadsHandler19502026/09/23 13:18:07 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001951--- PASS: TestSkippedUploadsHandler (0.00s)1952=== CONT TestService_AuthMiddleware_MTLSBoundSubjects19532026/09/23 13:18:07 OK 20241026095416_initial_model.sql (69.74ms)19542026/09/23 13:18:07 OK 20251218171726_add_pins.sql (17.26ms)19552026/09/23 13:18:07 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)19562026/09/23 13:18:07 OK 20241026095416_initial_model.sql (65.67ms)19572026/09/23 13:18:07 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)19582026/09/23 13:18:07 OK 20251218171726_add_pins.sql (15.64ms)19592026/09/23 13:18:07 OK 20260628120000_add_object_size_and_stats.sql (16.82ms)19602026/09/23 13:18:07 OK 20251218171726_add_pins.sql (7.23ms)19612026/09/23 13:18:07 OK 20260905000000_add_claims.sql (7.11ms)19622026/09/23 13:18:07 OK 20260628120000_add_object_size_and_stats.sql (7.75ms)19632026/09/23 13:18:07 OK 20260920000000_drop_claims.sql (1.94ms)19642026/09/23 13:18:07 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)19652026/09/23 13:18:07 OK 20260905000000_add_claims.sql (2.67ms)19662026/09/23 13:18:07 OK 20260920000000_drop_claims.sql (931.13µs)19672026/09/23 13:18:07 OK 20260923120000_add_pushes.sql (1.69ms)19682026/09/23 13:18:07 goose: successfully migrated database to version: 2026092312000019692026/09/23 13:18:07 OK 20260923120000_add_pushes.sql (761.17µs)19702026/09/23 13:18:07 goose: successfully migrated database to version: 2026092312000019712026/09/23 13:18:07 OK 1_commit_pending_closure.sql (1.16ms)19722026/09/23 13:18:07 OK 1_commit_pending_closure.sql (779.54µs)19732026/09/23 13:18:07 OK 2_object_stats_trigger.sql (683.46µs)19742026/09/23 13:18:07 OK 2_object_stats_trigger.sql (217.71µs)19752026/09/23 13:18:07 OK 3_commit_push.sql (224.08µs)19762026/09/23 13:18:07 goose: up to current file version: 319772026/09/23 13:18:07 OK 3_commit_push.sql (226.83µs)19782026/09/23 13:18:07 goose: up to current file version: 319792026/09/23 13:18:07 OK 20260905000000_add_claims.sql (18.34ms)19802026/09/23 13:18:07 OK 20260920000000_drop_claims.sql (6.22ms)19812026/09/23 13:18:07 OK 20260923120000_add_pushes.sql (5.47ms)19822026/09/23 13:18:07 goose: successfully migrated database to version: 2026092312000019832026/09/23 13:18:07 OK 1_commit_pending_closure.sql (901.92µs)19842026/09/23 13:18:07 OK 2_object_stats_trigger.sql (218.67µs)19852026/09/23 13:18:07 OK 3_commit_push.sql (164.54µs)19862026/09/23 13:18:07 goose: up to current file version: 319872026-09-23 13:18:07.578 UTC [59758] ERROR: relation "goose_db_version" does not exist at character 3619882026-09-23 13:18:07.578 UTC [59758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19892026/09/23 13:18:07 INFO Received uploads request method=POST path=/api/pending_closures19902026/09/23 13:18:07 OK 20241026095416_initial_model.sql (63.21ms)19912026/09/23 13:18:07 OK 20251210153512_drop_unused_gin_index.sql (10.33ms)19922026/09/23 13:18:07 OK 20251218171726_add_pins.sql (29.24ms)19932026/09/23 13:18:07 OK 20260628120000_add_object_size_and_stats.sql (18.35ms)19942026/09/23 13:18:07 INFO Received uploads request method=POST path=/api/pending_closures19952026/09/23 13:18:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19962026/09/23 13:18:07 INFO Uploading dngpza5w8sg0xxrpzmyfnyh64dy5nhda-shared-dep (136B)19972026/09/23 13:18:07 OK 20260905000000_add_claims.sql (42.6ms)19982026/09/23 13:18:07 WARN Failed to register uploaded object key=dngpza5w8sg0xxrpzmyfnyh64dy5nhda.ls error="server returned 404: 404 page not found\n"19992026/09/23 13:18:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20002026/09/23 13:18:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20012026/09/23 13:18:07 INFO Signed narinfos id=2 count=120022026/09/23 13:18:07 INFO Uploading 1 narinfos20032026/09/23 13:18:07 OK 20260920000000_drop_claims.sql (19.99ms)20042026/09/23 13:18:07 OK 20260923120000_add_pushes.sql (12.27ms)20052026/09/23 13:18:07 goose: successfully migrated database to version: 2026092312000020062026/09/23 13:18:07 OK 1_commit_pending_closure.sql (1.03ms)20072026/09/23 13:18:07 OK 2_object_stats_trigger.sql (244.21µs)20082026/09/23 13:18:07 OK 3_commit_push.sql (179.96µs)20092026/09/23 13:18:07 goose: up to current file version: 320102026/09/23 13:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20112026/09/23 13:18:07 WARN Failed to register uploaded object key=dngpza5w8sg0xxrpzmyfnyh64dy5nhda.narinfo error="server returned 404: 404 page not found\n"20122026/09/23 13:18:07 INFO Completed upload id=220132026/09/23 13:18:07 INFO Upload complete. (141ms)20142026/09/23 13:18:07 INFO Received uploads request method=POST path=/api/pending_closures20152026/09/23 13:18:07 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20162026/09/23 13:18:07 INFO Uploading k9iw4yz8wsjgq2r2sbwy6wgy1y64l3ib-top (256B)20172026/09/23 13:18:07 INFO Uploading dngpza5w8sg0xxrpzmyfnyh64dy5nhda-shared-dep (136B)20182026/09/23 13:18:07 WARN Failed to register uploaded object key=k9iw4yz8wsjgq2r2sbwy6wgy1y64l3ib.ls error="server returned 404: 404 page not found\n"20192026/09/23 13:18:07 WARN Failed to register uploaded object key=nar/1j2b3sb9b0qqkcd7kh6l9xpvdglw4nnva0akykrsn0vpav0p8lfc.nar.zst error="server returned 404: 404 page not found\n"20202026/09/23 13:18:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"2021=== NAME TestClientMultipleUploads2022 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-59446-2641137695/TestClientMultipleUploads3565436893/001/store/8c34qyiyzjksri286mnla36khpwhvp9b-test-file-0.txt20232026/09/23 13:18:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20242026/09/23 13:18:07 INFO Signed narinfos id=1 count=120252026/09/23 13:18:07 WARN Failed to register uploaded object key=dngpza5w8sg0xxrpzmyfnyh64dy5nhda.ls error="server returned 404: 404 page not found\n"20262026/09/23 13:18:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20272026/09/23 13:18:07 INFO Signed narinfos id=3 count=120282026/09/23 13:18:07 INFO Uploading 2 narinfos20292026/09/23 13:18:07 WARN Failed to register uploaded object key=k9iw4yz8wsjgq2r2sbwy6wgy1y64l3ib.narinfo error="server returned 404: 404 page not found\n"20302026/09/23 13:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20312026/09/23 13:18:07 WARN Failed to register uploaded object key=dngpza5w8sg0xxrpzmyfnyh64dy5nhda.narinfo error="server returned 404: 404 page not found\n"20322026/09/23 13:18:07 INFO Completed upload id=120332026/09/23 13:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20342026/09/23 13:18:07 INFO Completed upload id=320352026/09/23 13:18:07 INFO Upload complete. (312ms)2036=== NAME TestClientSharedPathCommittedMidPush2037 client_integration_test.go:680: Retrieved narinfo from S3:2038 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientSharedPathCommittedMidPush36137216/001/store/dngpza5w8sg0xxrpzmyfnyh64dy5nhda-shared-dep2039 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2040 Compression: zstd2041 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822042 NarSize: 1362043 References: 2044 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2045 client_integration_test.go:680: Retrieved narinfo from S3:2046 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientSharedPathCommittedMidPush36137216/001/store/k9iw4yz8wsjgq2r2sbwy6wgy1y64l3ib-top2047 URL: nar/1j2b3sb9b0qqkcd7kh6l9xpvdglw4nnva0akykrsn0vpav0p8lfc.nar.zst2048 Compression: zstd2049 NarHash: sha256:1j2b3sb9b0qqkcd7kh6l9xpvdglw4nnva0akykrsn0vpav0p8lfc2050 NarSize: 2562051 References: /nix/var/nix/builds/nix-59446-2641137695/TestClientSharedPathCommittedMidPush36137216/001/store/dngpza5w8sg0xxrpzmyfnyh64dy5nhda-shared-dep2052 CA: text:sha256:1sgknn5qad41qnm58wk3va8misfkgi8dvw7nl5fxs8a9arkcfdmj2053=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2054=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2055=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2056=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2057=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2058=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2059=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2060=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2061=== CONT TestService_ReadAuthMiddleware2062=== NAME TestClientMultipleUploads2063 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-59446-2641137695/TestClientMultipleUploads3565436893/001/store/6l3qaqbiz7cipwg49kriinx9ybnghccw-test-file-1.txt2064=== NAME TestOrphanedObjectsGCStressTest2065 orphaned_objects_gc_test.go:509: Stress test completed successfully:2066 orphaned_objects_gc_test.go:510: - Active objects preserved: 202067 orphaned_objects_gc_test.go:511: - Objects deleted: 2102068 orphaned_objects_gc_test.go:512: - Total GC'd: 2102069--- PASS: TestOrphanedObjectsGCStressTest (9.94s)2070=== CONT TestService_AuthMiddleware_MTLSProxyHeader2071--- PASS: TestClientSharedPathCommittedMidPush (2.15s)2072=== CONT TestClientErrorHandling2073=== RUN TestClientErrorHandling/InvalidStorePath2074=== PAUSE TestClientErrorHandling/InvalidStorePath2075=== RUN TestClientErrorHandling/InvalidAuthToken2076=== PAUSE TestClientErrorHandling/InvalidAuthToken2077=== RUN TestClientErrorHandling/ServerNotAvailable2078=== PAUSE TestClientErrorHandling/ServerNotAvailable2079=== CONT TestPresignedUploadRegisteredBeforeCommit20802026/09/23 13:18:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02081=== NAME TestClientMultipleUploads2082 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-59446-2641137695/TestClientMultipleUploads3565436893/001/store/j9rl55g7bdm8ikrq8r2wbgxzkr4kgv5w-test-file-2.txt2083=== NAME TestPinProtectsFromGC2084 client_integration_test.go:794: Pin successfully protected closure from garbage collection2085--- PASS: TestPinProtectsFromGC (6.25s)2086=== CONT TestClientCADerivations20872026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures20882026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures20892026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures20902026/09/23 13:18:08 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20912026/09/23 13:18:08 INFO Uploading 8c34qyiyzjksri286mnla36khpwhvp9b-test-file-0.txt (160B)20922026/09/23 13:18:08 INFO Uploading j9rl55g7bdm8ikrq8r2wbgxzkr4kgv5w-test-file-2.txt (160B)20932026/09/23 13:18:08 INFO Uploading 6l3qaqbiz7cipwg49kriinx9ybnghccw-test-file-1.txt (160B)20942026/09/23 13:18:08 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20952026/09/23 13:18:08 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20962026/09/23 13:18:08 WARN Failed to register uploaded object key=6l3qaqbiz7cipwg49kriinx9ybnghccw.ls error="server returned 404: 404 page not found\n"20972026/09/23 13:18:08 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20982026/09/23 13:18:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20992026/09/23 13:18:08 WARN Failed to register uploaded object key=8c34qyiyzjksri286mnla36khpwhvp9b.ls error="server returned 404: 404 page not found\n"21002026/09/23 13:18:08 WARN Failed to register uploaded object key=j9rl55g7bdm8ikrq8r2wbgxzkr4kgv5w.ls error="server returned 404: 404 page not found\n"21012026/09/23 13:18:08 INFO Signed narinfos id=1 count=121022026/09/23 13:18:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21032026/09/23 13:18:08 INFO Signed narinfos id=2 count=121042026/09/23 13:18:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21052026/09/23 13:18:08 INFO Signed narinfos id=3 count=121062026/09/23 13:18:08 INFO Uploading 3 narinfos21072026/09/23 13:18:08 WARN Failed to register uploaded object key=8c34qyiyzjksri286mnla36khpwhvp9b.narinfo error="server returned 404: 404 page not found\n"21082026/09/23 13:18:08 WARN Failed to register uploaded object key=6l3qaqbiz7cipwg49kriinx9ybnghccw.narinfo error="server returned 404: 404 page not found\n"21092026/09/23 13:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21102026/09/23 13:18:08 WARN Failed to register uploaded object key=j9rl55g7bdm8ikrq8r2wbgxzkr4kgv5w.narinfo error="server returned 404: 404 page not found\n"21112026/09/23 13:18:08 INFO Completed upload id=121122026/09/23 13:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21132026/09/23 13:18:08 INFO Completed upload id=221142026/09/23 13:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21152026/09/23 13:18:08 INFO Completed upload id=321162026/09/23 13:18:08 INFO Upload complete. (196ms)2117=== NAME TestClientMultipleUploads2118 client_integration_test.go:369: Uploaded 3 paths in 232.426875ms2119--- PASS: TestClientMultipleUploads (2.06s)2120=== CONT TestClientIntegration21212026-09-23 13:18:08.437 UTC [59788] ERROR: relation "goose_db_version" does not exist at character 3621222026-09-23 13:18:08.437 UTC [59788] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2123--- PASS: TestService_ReadScope_PublicByDefault (1.73s)2124=== CONT TestPush_RejectsBadRequests/no_roots21252026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes2126=== CONT TestPush_RejectsBadRequests/bad_root21272026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes2128=== CONT TestPush_RejectsBadRequests/root_not_in_objects21292026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes2130=== CONT TestPush_RejectsBadRequests/no_objects21312026/09/23 13:18:08 INFO Received push request method=POST path=/api/pushes2132=== CONT TestIsValidCachePath/narinfo2133--- PASS: TestPush_RejectsBadRequests (1.32s)2134 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2135 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2136 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2137 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2138=== CONT TestIsValidCachePath/index.html2139=== CONT TestIsValidCachePath/short_hash2140=== CONT TestIsValidCachePath/wrong_extension2141=== CONT TestIsValidCachePath/leading_slash2142=== CONT TestIsValidCachePath/empty2143=== CONT TestIsValidCachePath/random_path2144=== CONT TestIsValidCachePath/invalid_char_u2145=== CONT TestIsValidCachePath/invalid_char_e2146=== CONT TestIsValidCachePath/traversal_in_middle2147=== CONT TestIsValidCachePath/traversal_parent2148=== CONT TestIsValidCachePath/nar_uncompressed2149=== CONT TestIsValidCachePath/nix-cache-info2150=== CONT TestIsValidCachePath/realisation2151=== CONT TestIsValidCachePath/log2152=== CONT TestIsValidCachePath/ls2153=== CONT TestIsValidCachePath/nar_xz2154=== CONT TestIsValidCachePath/nar_bz22155=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2156=== CONT TestIsValidCachePath/nar_zst2157--- PASS: TestIsValidCachePath (0.00s)2158 --- PASS: TestIsValidCachePath/narinfo (0.00s)2159 --- PASS: TestIsValidCachePath/index.html (0.00s)2160 --- PASS: TestIsValidCachePath/short_hash (0.00s)2161 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2162 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2163 --- PASS: TestIsValidCachePath/empty (0.00s)2164 --- PASS: TestIsValidCachePath/random_path (0.00s)2165 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2166 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2167 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2168 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2169 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2170 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2171 --- PASS: TestIsValidCachePath/realisation (0.00s)2172 --- PASS: TestIsValidCachePath/log (0.00s)2173 --- PASS: TestIsValidCachePath/ls (0.00s)2174 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2175 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2176 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2177 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2178=== CONT TestParseSingleRange/none2179=== CONT TestParseSingleRange/open-ended2180=== CONT TestParseSingleRange/start_far_past_EOF2181=== CONT TestParseSingleRange/start_past_EOF2182=== CONT TestParseSingleRange/single_byte2183=== CONT TestParseSingleRange/suffix_exceeds_size2184=== CONT TestParseSingleRange/suffix2185=== CONT TestParseSingleRange/end_clamped_to_size2186=== CONT TestParseSingleRange/malformed_both_empty2187=== CONT TestParseSingleRange/closed2188=== CONT TestParseSingleRange/malformed_end_before_start2189=== CONT TestParseSingleRange/multi-range_ignored2190=== CONT TestParseSingleRange/malformed_no_dash2191=== CONT TestParseSingleRange/unknown_unit2192--- PASS: TestParseSingleRange (0.00s)2193 --- PASS: TestParseSingleRange/none (0.00s)2194 --- PASS: TestParseSingleRange/open-ended (0.00s)2195 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2196 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2197 --- PASS: TestParseSingleRange/single_byte (0.00s)2198 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2199 --- PASS: TestParseSingleRange/suffix (0.00s)2200 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2201 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2202 --- PASS: TestParseSingleRange/closed (0.00s)2203 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2204 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2205 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2206 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2207=== CONT TestServerTLSConfig/no_client_CA2208=== CONT TestServerTLSConfig/not_a_PEM_file2209=== CONT TestServerTLSConfig/missing_CA_file2210--- PASS: TestServerTLSConfig (0.00s)2211 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2212 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2213 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2214=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22152026/09/23 13:18:08 INFO Received request for more parts method=POST path=/2216=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure22172026/09/23 13:18:08 INFO Received uploads request method=POST path=/22182026-09-23 13:18:08.532 UTC [59792] ERROR: relation "goose_db_version" does not exist at character 3622192026-09-23 13:18:08.532 UTC [59792] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22202026-09-23 13:18:08.538 UTC [59793] ERROR: relation "goose_db_version" does not exist at character 3622212026-09-23 13:18:08.538 UTC [59793] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22222026/09/23 13:18:08 OK 20241026095416_initial_model.sql (91.39ms)22232026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (994.83µs)22242026/09/23 13:18:08 OK 20251218171726_add_pins.sql (9.8ms)22252026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (11.36ms)2226=== NAME TestClientWithDependencies2227 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-59446-2641137695/TestClientWithDependencies3352540103/001/store/cgf5i219w98q8m5ifl1vb7syzmz67f99-test-script22282026/09/23 13:18:08 OK 20241026095416_initial_model.sql (39.87ms)22292026/09/23 13:18:08 OK 20260905000000_add_claims.sql (3.48ms)22302026/09/23 13:18:08 OK 20241026095416_initial_model.sql (26.64ms)22312026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)22322026/09/23 13:18:08 OK 20251210153512_drop_unused_gin_index.sql (737.88µs)22332026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (1.41ms)22342026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (1.83ms)22352026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000022362026/09/23 13:18:08 OK 20251218171726_add_pins.sql (1.99ms)22372026/09/23 13:18:08 OK 20251218171726_add_pins.sql (2.71ms)22382026/09/23 13:18:08 OK 1_commit_pending_closure.sql (2.11ms)22392026/09/23 13:18:08 OK 2_object_stats_trigger.sql (383.08µs)22402026/09/23 13:18:08 OK 3_commit_push.sql (277.33µs)22412026/09/23 13:18:08 goose: up to current file version: 322422026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (3.1ms)22432026/09/23 13:18:08 OK 20260628120000_add_object_size_and_stats.sql (2.59ms)22442026/09/23 13:18:08 OK 20260905000000_add_claims.sql (2.88ms)22452026/09/23 13:18:08 OK 20260905000000_add_claims.sql (2.92ms)22462026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (13.23ms)22472026/09/23 13:18:08 OK 20260920000000_drop_claims.sql (18.38ms)22482026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (10.22ms)22492026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000022502026/09/23 13:18:08 OK 1_commit_pending_closure.sql (801µs)22512026/09/23 13:18:08 OK 2_object_stats_trigger.sql (230.88µs)22522026/09/23 13:18:08 OK 3_commit_push.sql (161.63µs)22532026/09/23 13:18:08 goose: up to current file version: 322542026/09/23 13:18:08 OK 20260923120000_add_pushes.sql (17.59ms)22552026/09/23 13:18:08 goose: successfully migrated database to version: 2026092312000022562026/09/23 13:18:08 OK 1_commit_pending_closure.sql (875.13µs)22572026/09/23 13:18:08 OK 2_object_stats_trigger.sql (224.96µs)22582026/09/23 13:18:08 OK 3_commit_push.sql (184.63µs)22592026/09/23 13:18:08 goose: up to current file version: 32260 client_integration_test.go:615: Found 1 dependencies (including self)22612026/09/23 13:18:08 INFO Received uploads request method=POST path=/api/pending_closures22622026/09/23 13:18:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22632026/09/23 13:18:08 INFO Uploading cgf5i219w98q8m5ifl1vb7syzmz67f99-test-script (136B)22642026/09/23 13:18:08 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"22652026/09/23 13:18:08 WARN Failed to register uploaded object key=cgf5i219w98q8m5ifl1vb7syzmz67f99.ls error="server returned 404: 404 page not found\n"2266=== RUN TestService_RequireScope_OIDC/builder_may_write2267=== PAUSE TestService_RequireScope_OIDC/builder_may_write2268=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2269=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2270=== RUN TestService_RequireScope_OIDC/ops_may_admin2271=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2272=== RUN TestService_RequireScope_OIDC/ops_may_not_write2273=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2274=== RUN TestService_RequireScope_OIDC/reader_may_not_write2275=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2276=== RUN TestService_RequireScope_OIDC/static_token_may_admin2277=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2278=== RUN TestService_RequireScope_OIDC/static_token_may_write2279=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2280=== RUN TestService_RequireScope_OIDC/reader_may_read2281=== PAUSE TestService_RequireScope_OIDC/reader_may_read2282=== RUN TestService_RequireScope_OIDC/writer_implies_read2283=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2284=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2285=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2286=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22872026/09/23 13:18:08 INFO Received complete multipart upload request method=POST path=/22882026/09/23 13:18:08 WARN Failed to register uploaded object key=log/5ixniq2hs638g8qlh8gkxai4s1ikzxp1-test-script.drv error="server returned 404: 404 page not found\n"22892026/09/23 13:18:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22902026/09/23 13:18:08 INFO Signed narinfos id=1 count=122912026/09/23 13:18:08 INFO Uploading 1 narinfos2292=== CONT TestProxyWriteTimeout/narinfo2293=== CONT TestProxyWriteTimeout/10_GiB_nar2294=== CONT TestProxyWriteTimeout/unknown_size2295=== CONT TestProxyWriteTimeout/1_GiB_nar2296--- PASS: TestProxyWriteTimeout (0.00s)2297 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2298 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2299 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2300 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2301=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23022026/09/23 13:18:08 INFO Received uploads request method=POST path=/2303=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23042026/09/23 13:18:08 INFO Received complete multipart upload request method=POST path=/2305=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23062026/09/23 13:18:08 INFO Received request for more parts method=POST path=/2307=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23082026/09/23 13:18:08 INFO Received uploads request method=POST path=/2309--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2310 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2311 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2312 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2313 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2314=== CONT TestIsValidUploadKey/narinfo2315=== CONT TestIsValidUploadKey/realisation_plus_in_output2316=== CONT TestIsValidUploadKey/unknown_type2317=== CONT TestIsValidUploadKey/empty_key2318=== CONT TestIsValidUploadKey/absolute2319=== CONT TestIsValidUploadKey/traversal_nar2320=== CONT TestIsValidUploadKey/traversal2321=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2322=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2323=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2324=== CONT TestIsValidUploadKey/index.html2325=== CONT TestIsValidUploadKey/nix-cache-info2326=== CONT TestIsValidUploadKey/build_log_home-manager_file2327=== CONT TestIsValidUploadKey/realisation2328=== CONT TestIsValidUploadKey/build_log_equals2329=== CONT TestIsValidUploadKey/build_log_question_mark2330=== CONT TestIsValidUploadKey/nar_plain2331=== CONT TestIsValidUploadKey/build_log2332=== CONT TestIsValidUploadKey/listing2333=== CONT TestIsValidUploadKey/nar_xz2334=== CONT TestIsValidUploadKey/nar_zst2335=== CONT TestIsValidUploadKey/build_log_plus_in_name2336--- PASS: TestIsValidUploadKey (0.00s)2337 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2338 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2339 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2340 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2341 --- PASS: TestIsValidUploadKey/absolute (0.00s)2342 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2343 --- PASS: TestIsValidUploadKey/traversal (0.00s)2344 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2345 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2346 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2347 --- PASS: TestIsValidUploadKey/index.html (0.00s)2348 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2349 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2350 --- PASS: TestIsValidUploadKey/realisation (0.00s)2351 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2352 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2353 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2354 --- PASS: TestIsValidUploadKey/build_log (0.00s)2355 --- PASS: TestIsValidUploadKey/listing (0.00s)2356 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2357 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2358 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2359=== CONT TestResolveDBConnectionString/flag_wins2360=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2361=== CONT TestResolveDBConnectionString/nothing_configured2362=== CONT TestResolveDBConnectionString/missing_file_is_an_error2363=== CONT TestResolveDBConnectionString/file_when_flag_empty2364=== CONT TestCacheConfigHandler/full_config,_no_issuer2365=== CONT TestCacheConfigHandler/no_signing_keys2366=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2367=== CONT TestCacheConfigHandler/no_cache_url_configured2368--- PASS: TestCacheConfigHandler (0.00s)2369 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2370 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2371 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2372 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2373=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2374=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2375=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected23762026/09/23 13:18:08 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]2377=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected23782026/09/23 13:18:08 WARN Authentication failed token_preview=eyJhbGciOi...2xrOG-M8mQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2379=== CONT TestClientErrorHandling/InvalidStorePath2380--- PASS: TestResolveDBConnectionString (0.02s)2381 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2382 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2383 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2384 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2385 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2386--- PASS: TestService_AuthMiddleware_OIDC (1.61s)2387 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2388 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2389 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2390 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)23912026/09/23 13:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23922026/09/23 13:18:08 WARN Failed to register uploaded object key=cgf5i219w98q8m5ifl1vb7syzmz67f99.narinfo error="server returned 404: 404 page not found\n"2393=== CONT TestClientErrorHandling/ServerNotAvailable2394--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2395 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2396 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2397 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)23982026/09/23 13:18:08 INFO Completed upload id=123992026/09/23 13:18:08 INFO Upload complete. (186ms)2400=== NAME TestClientWithDependencies2401 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-59446-2641137695/TestClientWithDependencies3352540103/001/store) requires matching store prefix2402--- PASS: TestClientWithDependencies (2.76s)2403=== CONT TestClientErrorHandling/InvalidAuthToken24042026/09/23 13:18:09 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24052026/09/23 13:18:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"24062026/09/23 13:18:09 WARN mTLS auth: bound subjects configured but subject DN unavailable24072026/09/23 13:18:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2408--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.58s)2409=== CONT TestService_RequireScope_OIDC/builder_may_write2410=== CONT TestService_RequireScope_OIDC/static_token_may_admin2411=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2412=== CONT TestService_RequireScope_OIDC/writer_implies_read2413=== CONT TestService_RequireScope_OIDC/reader_may_read2414=== CONT TestService_RequireScope_OIDC/static_token_may_write2415=== CONT TestService_RequireScope_OIDC/ops_may_not_write2416=== CONT TestService_RequireScope_OIDC/reader_may_not_write2417=== CONT TestService_RequireScope_OIDC/ops_may_admin2418=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2419--- PASS: TestService_RequireScope_OIDC (1.59s)2420 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2421 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2422 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2423 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2424 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2425 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2426 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2427 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2428 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2429 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)24302026/09/23 13:18:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.190743ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24312026/09/23 13:18:09 INFO Received uploads request method=POST path=/api/pending_closures24322026/09/23 13:18:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.33289ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24332026-09-23 13:18:09.558 UTC [59809] ERROR: relation "goose_db_version" does not exist at character 3624342026-09-23 13:18:09.558 UTC [59809] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24352026-09-23 13:18:09.559 UTC [59808] ERROR: relation "goose_db_version" does not exist at character 3624362026-09-23 13:18:09.559 UTC [59808] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24372026-09-23 13:18:09.600 UTC [59811] ERROR: relation "goose_db_version" does not exist at character 3624382026-09-23 13:18:09.600 UTC [59811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24392026-09-23 13:18:09.605 UTC [59810] ERROR: relation "goose_db_version" does not exist at character 3624402026-09-23 13:18:09.605 UTC [59810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24412026/09/23 13:18:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24422026-09-23 13:18:09.679 UTC [59812] ERROR: relation "goose_db_version" does not exist at character 3624432026-09-23 13:18:09.679 UTC [59812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24442026/09/23 13:18:09 OK 20241026095416_initial_model.sql (81.94ms)24452026/09/23 13:18:09 OK 20241026095416_initial_model.sql (81.9ms)24462026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (8.49ms)24472026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (8.27ms)24482026/09/23 13:18:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=826.880902ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24492026/09/23 13:18:09 OK 20251218171726_add_pins.sql (4.83ms)24502026/09/23 13:18:09 OK 20241026095416_initial_model.sql (55.22ms)24512026/09/23 13:18:09 OK 20241026095416_initial_model.sql (55.97ms)24522026/09/23 13:18:09 OK 20251218171726_add_pins.sql (6.05ms)24532026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)24542026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)24552026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (5.87ms)24562026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (10.79ms)24572026/09/23 13:18:09 OK 20251218171726_add_pins.sql (10.27ms)24582026/09/23 13:18:09 OK 20251218171726_add_pins.sql (18.08ms)24592026/09/23 13:18:09 OK 20260905000000_add_claims.sql (17.19ms)24602026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (15.2ms)24612026/09/23 13:18:09 OK 20260905000000_add_claims.sql (17.12ms)24622026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (14.93ms)24632026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (10.16ms)24642026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (19.66ms)24652026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (5.15ms)24662026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000024672026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (4ms)24682026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000024692026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.74ms)24702026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.83ms)24712026/09/23 13:18:09 OK 2_object_stats_trigger.sql (508.92µs)24722026/09/23 13:18:09 OK 2_object_stats_trigger.sql (534.88µs)24732026/09/23 13:18:09 OK 3_commit_push.sql (493.29µs)24742026/09/23 13:18:09 goose: up to current file version: 324752026/09/23 13:18:09 OK 3_commit_push.sql (557.29µs)24762026/09/23 13:18:09 goose: up to current file version: 324772026/09/23 13:18:09 OK 20260905000000_add_claims.sql (22.52ms)24782026/09/23 13:18:09 OK 20241026095416_initial_model.sql (69.47ms)24792026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (27.14ms)24802026/09/23 13:18:09 OK 20251210153512_drop_unused_gin_index.sql (10.95ms)24812026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (12.15ms)24822026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000024832026/09/23 13:18:09 OK 20260905000000_add_claims.sql (48.58ms)24842026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.79ms)24852026/09/23 13:18:09 OK 2_object_stats_trigger.sql (530.38µs)24862026/09/23 13:18:09 OK 3_commit_push.sql (361.33µs)24872026/09/23 13:18:09 goose: up to current file version: 324882026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (8.06ms)24892026/09/23 13:18:09 OK 20251218171726_add_pins.sql (15.52ms)24902026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (2.76ms)24912026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000024922026/09/23 13:18:09 OK 1_commit_pending_closure.sql (2.49ms)24932026/09/23 13:18:09 OK 2_object_stats_trigger.sql (461µs)24942026/09/23 13:18:09 OK 3_commit_push.sql (310.17µs)24952026/09/23 13:18:09 goose: up to current file version: 324962026/09/23 13:18:09 OK 20260628120000_add_object_size_and_stats.sql (21.92ms)24972026/09/23 13:18:09 OK 20260905000000_add_claims.sql (38.45ms)24982026/09/23 13:18:09 OK 20260920000000_drop_claims.sql (16.21ms)24992026/09/23 13:18:09 OK 20260923120000_add_pushes.sql (7.22ms)25002026/09/23 13:18:09 goose: successfully migrated database to version: 2026092312000025012026/09/23 13:18:09 OK 1_commit_pending_closure.sql (4.39ms)25022026/09/23 13:18:09 OK 2_object_stats_trigger.sql (991.5µs)25032026/09/23 13:18:09 OK 3_commit_push.sql (940.21µs)25042026/09/23 13:18:09 goose: up to current file version: 325052026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures25062026/09/23 13:18:10 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst25072026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures2508--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.35s)25092026-09-23 13:18:10.368 UTC [59818] ERROR: relation "goose_db_version" does not exist at character 3625102026-09-23 13:18:10.368 UTC [59818] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25112026-09-23 13:18:10.395 UTC [59819] ERROR: relation "goose_db_version" does not exist at character 3625122026-09-23 13:18:10.395 UTC [59819] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2513--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.53s)2514=== NAME TestClientCADerivations2515 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-59446-2641137695/TestClientCADerivations4252626679/001/store/jwyyyvzjq33v6cilxmbrcx9697w4nqxs-ca-test25162026/09/23 13:18:10 OK 20241026095416_initial_model.sql (103.06ms)25172026/09/23 13:18:10 OK 20251210153512_drop_unused_gin_index.sql (13.16ms)25182026/09/23 13:18:10 OK 20251218171726_add_pins.sql (5.3ms)25192026/09/23 13:18:10 OK 20241026095416_initial_model.sql (99.93ms)2520 client_ca_test.go:139: Found 1 dependencies (including self)25212026/09/23 13:18:10 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)25222026/09/23 13:18:10 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)25232026/09/23 13:18:10 OK 20251218171726_add_pins.sql (1.2ms)25242026/09/23 13:18:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.695903311s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25252026/09/23 13:18:10 OK 20260905000000_add_claims.sql (7.45ms)25262026/09/23 13:18:10 OK 20260628120000_add_object_size_and_stats.sql (10.64ms)25272026/09/23 13:18:10 OK 20260920000000_drop_claims.sql (3.99ms)25282026/09/23 13:18:10 OK 20260923120000_add_pushes.sql (1.27ms)25292026/09/23 13:18:10 goose: successfully migrated database to version: 2026092312000025302026/09/23 13:18:10 OK 1_commit_pending_closure.sql (774.54µs)25312026/09/23 13:18:10 OK 2_object_stats_trigger.sql (195µs)25322026/09/23 13:18:10 OK 3_commit_push.sql (162.29µs)25332026/09/23 13:18:10 goose: up to current file version: 325342026/09/23 13:18:10 OK 20260905000000_add_claims.sql (9.67ms)25352026/09/23 13:18:10 OK 20260920000000_drop_claims.sql (8.04ms)25362026/09/23 13:18:10 OK 20260923120000_add_pushes.sql (1.13ms)25372026/09/23 13:18:10 goose: successfully migrated database to version: 2026092312000025382026/09/23 13:18:10 OK 1_commit_pending_closure.sql (956.5µs)25392026/09/23 13:18:10 OK 2_object_stats_trigger.sql (241.21µs)25402026/09/23 13:18:10 OK 3_commit_push.sql (813.42µs)25412026/09/23 13:18:10 goose: up to current file version: 325422026/09/23 13:18:10 INFO Received uploads request method=POST path=/api/pending_closures2543--- PASS: TestService_ReadAuthMiddleware (2.72s)25442026/09/23 13:18:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25452026/09/23 13:18:10 INFO Uploading jwyyyvzjq33v6cilxmbrcx9697w4nqxs-ca-test (144B)25462026/09/23 13:18:10 WARN Failed to register uploaded object key=jwyyyvzjq33v6cilxmbrcx9697w4nqxs.ls error="server returned 404: 404 page not found\n"25472026/09/23 13:18:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25482026/09/23 13:18:10 WARN Failed to register uploaded object key=log/imkl2qg0n7fm96h9pr9nj3hxlqjiyg6f-ca-test.drv error="server returned 404: 404 page not found\n"25492026/09/23 13:18:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25502026/09/23 13:18:10 INFO Signed narinfos id=1 count=125512026/09/23 13:18:10 INFO Uploading 1 narinfos25522026/09/23 13:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25532026/09/23 13:18:10 WARN Failed to register uploaded object key=jwyyyvzjq33v6cilxmbrcx9697w4nqxs.narinfo error="server returned 404: 404 page not found\n"25542026/09/23 13:18:10 INFO Completed upload id=125552026/09/23 13:18:10 INFO Upload complete. (168ms)2556=== NAME TestClientCADerivations2557 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientCADerivations4252626679/001/store/jwyyyvzjq33v6cilxmbrcx9697w4nqxs-ca-test2558 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2559 Compression: zstd2560 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2561 NarSize: 1442562 References: 2563 Deriver: /nix/var/nix/builds/nix-59446-2641137695/TestClientCADerivations4252626679/001/store/imkl2qg0n7fm96h9pr9nj3hxlqjiyg6f-ca-test.drv2564 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2565 client_ca_test.go:185: Checking for realisation files in S3...2566 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2567 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2568 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket59?endpoint=http://localhost:58029®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-59446-2641137695/TestClientCADerivations4252626679/001/store'2569 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12570--- PASS: TestClientCADerivations (2.80s)2571=== NAME TestClientIntegration2572 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-59446-2641137695/TestClientIntegration2390707567/002/store/a5dl9naw6xa7iz15s49xs5zd7i3j0g67-test-file.txt25732026/09/23 13:18:11 INFO Received uploads request method=POST path=/api/pending_closures25742026/09/23 13:18:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25752026/09/23 13:18:11 INFO Uploading a5dl9naw6xa7iz15s49xs5zd7i3j0g67-test-file.txt (152B)25762026/09/23 13:18:11 WARN Failed to register uploaded object key=a5dl9naw6xa7iz15s49xs5zd7i3j0g67.ls error="server returned 404: 404 page not found\n"25772026/09/23 13:18:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25782026/09/23 13:18:11 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"25792026/09/23 13:18:11 INFO Signed narinfos id=1 count=125802026/09/23 13:18:11 INFO Uploading 1 narinfos25812026/09/23 13:18:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25822026/09/23 13:18:11 WARN Failed to register uploaded object key=a5dl9naw6xa7iz15s49xs5zd7i3j0g67.narinfo error="server returned 404: 404 page not found\n"25832026/09/23 13:18:11 INFO Completed upload id=125842026/09/23 13:18:11 INFO Upload complete. (97ms)25852026/09/23 13:18:11 INFO All 1 paths already cached2586 client_integration_test.go:312: Retrieved narinfo from S3:2587 StorePath: /nix/var/nix/builds/nix-59446-2641137695/TestClientIntegration2390707567/002/store/a5dl9naw6xa7iz15s49xs5zd7i3j0g67-test-file.txt2588 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2589 Compression: zstd2590 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12591 NarSize: 1522592 References: 2593 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12594 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2595 client_integration_test.go:313: Decompressed .ls content (64 bytes):2596 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2597 client_integration_test.go:316: Testing garbage collection...25982026/09/23 13:18:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures25992026/09/23 13:18:11 INFO Garbage collection started26002026/09/23 13:18:11 INFO Aborted multipart uploads count=026012026/09/23 13:18:11 WARN Force mode enabled - objects will be deleted immediately without grace period26022026/09/23 13:18:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26032026/09/23 13:18:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26042026/09/23 13:18:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=026052026/09/23 13:18:11 INFO Vacuumed table table=pending_closures26062026/09/23 13:18:11 INFO Vacuumed table table=pending_objects26072026/09/23 13:18:11 INFO Vacuumed table table=multipart_uploads26082026/09/23 13:18:11 INFO Vacuumed table table=closures26092026/09/23 13:18:11 INFO Vacuumed table table=objects26102026/09/23 13:18:12 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26112026/09/23 13:18:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.511815ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26122026/09/23 13:18:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.675307ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26132026/09/23 13:18:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=812.940396ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26142026/09/23 13:18:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02615 client_integration_test.go:323: Objects in database after GC:2616 client_integration_test.go:323: Successfully deleted all objects with GC --force2617--- PASS: TestClientIntegration (4.92s)26182026/09/23 13:18:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.576773862s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26192026/09/23 13:18:14 WARN Rate limiter enabled after throttle name=s3-test rate=526202026/09/23 13:18:14 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2621=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2622 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102623 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002624--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.74s)26252026/09/23 13:18:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"26262026/09/23 13:18:15 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26272026/09/23 13:18:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.779332ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26282026/09/23 13:18:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.8933ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26292026/09/23 13:18:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=743.493021ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26302026/09/23 13:18:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.705666096s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2631--- PASS: TestClientErrorHandling (0.00s)2632 --- PASS: TestClientErrorHandling/InvalidStorePath (2.52s)2633 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.38s)2634 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.80s)2635FAIL2636{"timestamp":"2026-09-23T13:18:18.605346Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58146","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}26372026-09-23 13:18:18.717 UTC [59484] LOG: received smart shutdown request26382026-09-23 13:18:18.717 UTC [59484] LOG: background worker "logical replication launcher" (PID 59494) exited with exit code 126392026-09-23 13:18:18.723 UTC [59489] LOG: shutting down26402026-09-23 13:18:18.723 UTC [59489] LOG: checkpoint starting: shutdown immediate26412026-09-23 13:18:19.895 UTC [59489] LOG: checkpoint complete: wrote 12941 buffers (79.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.751 s, sync=0.368 s, total=1.173 s; sync files=21874, longest=0.001 s, average=0.001 s; distance=302641 kB, estimate=302641 kB; lsn=0/13F196D0, redo lsn=0/13F196D026422026-09-23 13:18:19.900 UTC [59484] LOG: database system is shut down