niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #247
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestSetClientTLS68=== PAUSE TestSetClientTLS69=== RUN TestSetClientTLSDoesNotMutateDefaultTransport70=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport71=== RUN TestSetClientTLSErrors72=== PAUSE TestSetClientTLSErrors73=== RUN TestStaticToken74=== PAUSE TestStaticToken75=== RUN TestFileTokenReadsAndCaches76=== PAUSE TestFileTokenReadsAndCaches77=== RUN TestFileTokenMissing78=== PAUSE TestFileTokenMissing79=== RUN TestFileTokenEmpty80=== PAUSE TestFileTokenEmpty81=== RUN TestScriptTokenNoExpiryRerunsEveryCall82=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall83=== RUN TestScriptTokenCachesUntilRefresh84=== PAUSE TestScriptTokenCachesUntilRefresh85=== RUN TestScriptTokenEmptyToken86=== PAUSE TestScriptTokenEmptyToken87=== RUN TestScriptTokenBadJSON88=== PAUSE TestScriptTokenBadJSON89=== RUN TestScriptTokenScriptFails90=== PAUSE TestScriptTokenScriptFails91=== RUN TestScriptTokenEmptyCommand92=== PAUSE TestScriptTokenEmptyCommand93=== CONT TestScriptTokenBadJSON94=== CONT TestDoServerRequestAttachesToken95=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess96=== CONT TestRateLimiterFeedback97=== RUN TestRateLimiterFeedback/429_enables_limiter98=== PAUSE TestRateLimiterFeedback/429_enables_limiter99=== CONT TestPathInfoCACompatibility100=== RUN TestPathInfoCACompatibility/null_ca_field101=== PAUSE TestPathInfoCACompatibility/null_ca_field102=== RUN TestPathInfoCACompatibility/old_string_format_-_text103=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text104=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive105=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive106=== RUN TestPathInfoCACompatibility/new_structured_format_-_text107=== CONT TestParsePathInfoJSONMultiplePaths1082026/09/22 08:50:52 WARN Rate limiter enabled after throttle name=server-test rate=5109=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths110=== CONT TestParsePathInfoJSON111=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths112=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths113=== CONT TestGetStorePathHash114=== CONT TestConvertHashToNix32115=== CONT TestEncodeNixBase32WithRealHash116=== CONT TestEncodeNixBase32117=== CONT TestDumpPathWriterError118=== CONT TestDumpPathSingleFile119=== CONT TestDumpPathMatchesNix120=== CONT TestUploadMultipart_SupersededByPeer121=== CONT TestPartSizeForNAR122--- PASS: TestEncodeNixBase32WithRealHash (0.00s)123=== CONT TestFilterOversizedClosures124=== CONT TestStreamPushRequestLine125=== CONT TestResolveStorePath126=== CONT TestCaseHackSuffix127=== CONT TestStreamPushReportsSignatures128=== CONT TestRegisterUploadedObjectReusesConnections129=== CONT TestSetClientTLS130=== RUN TestRateLimiterFeedback/503_enables_limiter131=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text132=== RUN TestParsePathInfoJSON/Nix_format133=== CONT TestPathInfoHashCompatibility134=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths135=== RUN TestGetStorePathHash/valid_store_path136=== RUN TestConvertHashToNix32/SRI_format_to_Nix32137=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== RUN TestEncodeNixBase32/test_string_hash139=== RUN TestPartSizeForNAR/zero_stays_at_minimum140=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum141=== RUN TestPartSizeForNAR/small_stays_at_minimum142=== CONT TestStreamPushGivesUpOnDeadServer143=== PAUSE TestPartSizeForNAR/small_stays_at_minimum144=== RUN TestUploadMultipart_SupersededByPeer/exists145=== RUN TestFilterOversizedClosures/no_limit_keeps_everything146=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum1472026/09/22 08:50:52 ERROR Upload failed error="connection refused" count=201482026/09/22 08:50:52 ERROR Server seems unavailable, giving up on batch untried=171492026/09/22 08:50:52 ERROR Upload failed error=boom count=11502026/09/22 08:50:52 ERROR Upload failed error=boom count=1151=== CONT TestUploadMultipart_PartsInParallel152=== PAUSE TestParsePathInfoJSON/Nix_format153=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32154--- PASS: TestScriptTokenBadJSON (0.00s)155--- PASS: TestResolveStorePath (0.00s)156--- PASS: TestDoServerRequestAttachesToken (0.02s)157=== CONT TestStreamPushReportsEveryPath158--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)159--- PASS: TestStreamPushReportsSignatures (0.03s)160=== PAUSE TestGetStorePathHash/valid_store_path161=== RUN TestParsePathInfoJSON/Lix_format162=== RUN TestGetStorePathHash/basename_without_hyphen_should_error163=== CONT TestShellSplitErrors164=== RUN TestConvertHashToNix32/already_Nix32_format165=== PAUSE TestParsePathInfoJSON/Lix_format166--- PASS: TestShellSplitErrors (0.00s)167=== RUN TestParsePathInfoJSON/empty_input168=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)169=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum170=== PAUSE TestUploadMultipart_SupersededByPeer/exists171=== PAUSE TestEncodeNixBase32/test_string_hash172=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything173=== CONT TestShellSplit174=== PAUSE TestRateLimiterFeedback/503_enables_limiter175=== CONT TestDoWithRetry_BodyReplayedViaGetBody176=== PAUSE TestParsePathInfoJSON/empty_input177=== PAUSE TestConvertHashToNix32/already_Nix32_format178=== RUN TestConvertHashToNix32/invalid_format179=== PAUSE TestConvertHashToNix32/invalid_format180=== RUN TestParsePathInfoJSON/whitespace_only181=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon183=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method184=== CONT TestFileTokenMissing185=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter186=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method187=== CONT TestFileTokenReadsAndCaches188=== CONT TestStreamPushBatchesUnderLoad189=== CONT TestStreamPushIsolatesFailures190=== PAUSE TestParsePathInfoJSON/whitespace_only191=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error192=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter193=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI194=== RUN TestParsePathInfoJSON/invalid_JSON195=== PAUSE TestParsePathInfoJSON/invalid_JSON196=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1972026/09/22 08:50:52 WARN Rate limiter enabled after throttle name=server-test rate=5198--- PASS: TestShellSplit (0.00s)1992026/09/22 08:50:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45983200=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped201=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512202=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error203--- PASS: TestFileTokenReadsAndCaches (0.01s)204=== RUN TestUploadMultipart_SupersededByPeer/missing205=== CONT TestScriptTokenEmptyToken206=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512207=== RUN TestEncodeNixBase32/empty_input208=== RUN TestSetClientTLS/rejects_connection_without_client_cert209=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter210=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts211=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped212=== CONT TestStaticToken213=== PAUSE TestUploadMultipart_SupersededByPeer/missing214=== CONT TestScriptTokenCachesUntilRefresh215=== CONT TestSetClientTLSErrors216=== RUN TestFilterOversizedClosures/all_closures_skipped217--- PASS: TestCaseHackSuffix (0.04s)218--- PASS: TestFileTokenMissing (0.01s)219=== PAUSE TestEncodeNixBase32/empty_input220--- PASS: TestStreamPushReportsEveryPath (0.04s)221=== CONT TestScriptTokenEmptyCommand222=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2232026/09/22 08:50:52 WARN Rate limiter backed off name=server-test rate=5224=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2252026/09/22 08:50:52 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45983226=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter227--- PASS: TestScriptTokenEmptyCommand (0.00s)2282026/09/22 08:50:52 ERROR Upload failed error="bad path" count=3229=== CONT TestConvertHashToNix32/SRI_format_to_Nix32230=== CONT TestConvertHashToNix32/invalid_format231=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA232=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA233=== RUN TestSetClientTLS/preserves_debug_logging_transport234=== PAUSE TestSetClientTLS/preserves_debug_logging_transport235--- PASS: TestStaticToken (0.00s)236--- PASS: TestStreamPushIsolatesFailures (0.04s)237=== CONT TestPathInfoCACompatibility/new_structured_format_-_text238--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)239=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive240=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method241=== CONT TestPathInfoCACompatibility/old_string_format_-_text242=== CONT TestParsePathInfoJSON/Nix_format243=== CONT TestParsePathInfoJSON/invalid_JSON244=== CONT TestParsePathInfoJSON/whitespace_only245=== CONT TestParsePathInfoJSON/Lix_format246=== CONT TestParsePathInfoJSON/empty_input247=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512248--- PASS: TestParsePathInfoJSON (0.04s)249 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)250 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)251 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)252 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)253 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)254=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon255=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)256=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths257=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI258=== CONT TestUploadMultipart_SupersededByPeer/missing259--- PASS: TestPathInfoHashCompatibility (0.04s)260 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)261 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)262 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)263 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)264=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error265=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts266=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths267--- PASS: TestDumpPathSingleFile (0.07s)268=== CONT TestFileTokenEmpty269--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)271 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)272=== RUN TestSetClientTLSErrors/missing_cert_file273=== PAUSE TestSetClientTLSErrors/missing_cert_file274=== RUN TestSetClientTLSErrors/missing_key_file275=== PAUSE TestSetClientTLSErrors/missing_key_file276=== RUN TestSetClientTLSErrors/missing_ca_file277=== PAUSE TestSetClientTLSErrors/missing_ca_file278=== RUN TestSetClientTLSErrors/invalid_ca_file279=== PAUSE TestSetClientTLSErrors/invalid_ca_file280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter281=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter282--- PASS: TestFileTokenEmpty (0.00s)283=== CONT TestRateLimiterFeedback/503_enables_limiter284--- PASS: TestScriptTokenEmptyToken (0.03s)285=== CONT TestRateLimiterFeedback/429_enables_limiter286=== CONT TestConvertHashToNix32/already_Nix32_format287=== CONT TestPathInfoCACompatibility/null_ca_field288=== PAUSE TestFilterOversizedClosures/all_closures_skipped289=== CONT TestSetClientTLSDoesNotMutateDefaultTransport290=== CONT TestScriptTokenScriptFails291=== CONT TestUploadMultipart_SupersededByPeer/exists292=== CONT TestScriptTokenNoExpiryRerunsEveryCall293=== CONT TestEncodeNixBase32/test_string_hash294=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error295=== RUN TestPartSizeForNAR/1_TiB296=== CONT TestEncodeNixBase32/empty_input297=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA298=== CONT TestSetClientTLS/rejects_connection_without_client_cert299=== CONT TestSetClientTLS/preserves_debug_logging_transport300=== CONT TestSetClientTLSErrors/missing_cert_file301=== CONT TestSetClientTLSErrors/invalid_ca_file302=== PAUSE TestPartSizeForNAR/1_TiB303=== RUN TestPartSizeForNAR/5_TiB_S3_max_object304--- PASS: TestConvertHashToNix32 (0.03s)305 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)306 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)307 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)308--- PASS: TestEncodeNixBase32 (0.07s)309 --- PASS: TestEncodeNixBase32/empty_input (0.00s)310 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)311=== CONT TestSetClientTLSErrors/missing_key_file312=== CONT TestSetClientTLSErrors/missing_ca_file313=== CONT TestFilterOversizedClosures/no_limit_keeps_everything314=== CONT TestFilterOversizedClosures/all_closures_skipped315=== CONT TestGetStorePathHash/valid_store_path3162026/09/22 08:50:53 WARN Rate limiter enabled after throttle name=server-test rate=5317=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3182026/09/22 08:50:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35779319=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error320=== CONT TestGetStorePathHash/basename_without_hyphen_should_error321=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error322--- PASS: TestGetStorePathHash (0.08s)323 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)324 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)325 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)326 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)3272026/09/22 08:50:53 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=503282026/09/22 08:50:53 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=20003292026/09/22 08:50:53 WARN Rate limiter backed off name=server-test rate=5330--- PASS: TestFilterOversizedClosures (0.08s)331 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)332 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)333 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)334--- PASS: TestPathInfoCACompatibility (0.03s)335 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)336 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)337 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)338 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)339 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)340=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object341=== RUN TestPartSizeForNAR/capped_at_5_GiB342=== PAUSE TestPartSizeForNAR/capped_at_5_GiB343=== CONT TestPartSizeForNAR/zero_stays_at_minimum344=== CONT TestPartSizeForNAR/capped_at_5_GiB345=== CONT TestPartSizeForNAR/5_TiB_S3_max_object346=== CONT TestPartSizeForNAR/1_TiB347=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts348=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum349=== CONT TestPartSizeForNAR/small_stays_at_minimum350--- PASS: TestPartSizeForNAR (0.09s)351 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)352 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)353 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)354 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)355 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)356 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)357 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3582026/09/22 08:50:53 WARN Rate limiter enabled after throttle name=server-test rate=53592026/09/22 08:50:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:374213602026/09/22 08:50:53 WARN Rate limiter backed off name=server-test rate=5361--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)362 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)363 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)364--- PASS: TestScriptTokenScriptFails (0.00s)365--- PASS: TestRateLimiterFeedback (0.07s)366 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)367 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)368 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)369 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)370--- PASS: TestSetClientTLSErrors (0.00s)371 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)372 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)374 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)375--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)376--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)377--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)3782026/09/22 08:50:53 http: TLS handshake error from 127.0.0.1:56766: remote error: tls: bad certificate379--- PASS: TestRegisterUploadedObjectReusesConnections (0.10s)380--- PASS: TestSetClientTLS (0.07s)381 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)382 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)383 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)384--- PASS: TestStreamPushRequestLine (0.10s)385--- PASS: TestDumpPathWriterError (0.12s)386--- PASS: TestStreamPushBatchesUnderLoad (0.10s)387--- PASS: TestDumpPathMatchesNix (0.14s)388--- PASS: TestUploadMultipart_PartsInParallel (0.67s)389--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)390PASS391Running server tests...392The files belonging to this database system will be owned by user "nixbld".393This user must also own the server process.394395The database cluster will be initialized with locale "C".396The default database encoding has accordingly been set to "SQL_ASCII".397The default text search configuration will be set to "english".398399Data page checksums are enabled.400401creating directory /build/postgres1807246401/data ... ok402creating subdirectories ... ok403selecting dynamic shared memory implementation ... posix404selecting default "max_connections" ... 100405selecting default "shared_buffers" ... 128MB406selecting default time zone ... UTC407creating configuration files ... ok408running bootstrap script ... ok409performing post-bootstrap initialization ... ok410syncing data to disk ... ok411412initdb: warning: enabling "trust" authentication for local connections413initdb: 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.414415Success. You can now start the database server using:416417 pg_ctl -D /build/postgres1807246401/data -l logfile start418419/build/postgres1807246401:5432 - no response4202026-09-22 08:50:54.798 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4212026-09-22 08:50:54.798 UTC [129] LOG: listening on Unix socket "/build/postgres1807246401/.s.PGSQL.5432"4222026-09-22 08:50:54.802 UTC [136] LOG: database system was shut down at 2026-09-22 08:50:54 UTC4232026-09-22 08:50:54.806 UTC [129] LOG: database system is ready to accept connections424/build/postgres1807246401:5432 - accepting connections425{"timestamp":"2026-09-22T08:50:55.001251027Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f9ae8597-92c7-46f6-813c-50968ed67328","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(209)"}426=== RUN TestService_AuthMiddleware427=== PAUSE TestService_AuthMiddleware428=== RUN TestService_AuthMiddleware_MTLSProxyHeader429=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader430=== RUN TestService_AuthMiddleware_MTLSBoundSubjects431=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects432=== RUN TestService_ReadAuthMiddleware433=== PAUSE TestService_ReadAuthMiddleware434=== RUN TestService_AuthMiddleware_OIDC435=== PAUSE TestService_AuthMiddleware_OIDC436=== RUN TestService_RequireScope_OIDC437=== PAUSE TestService_RequireScope_OIDC438=== RUN TestService_ReadScope_PublicByDefault439=== PAUSE TestService_ReadScope_PublicByDefault440=== RUN TestCacheConfigHandler441=== PAUSE TestCacheConfigHandler442=== RUN TestCacheStatsHandler443=== PAUSE TestCacheStatsHandler444=== RUN TestClientCADerivations445=== PAUSE TestClientCADerivations446=== RUN TestClientErrorHandling447=== PAUSE TestClientErrorHandling448=== RUN TestClientIntegration449=== PAUSE TestClientIntegration450=== RUN TestClientMultipleUploads451=== PAUSE TestClientMultipleUploads452=== RUN TestClientWithDependencies453=== PAUSE TestClientWithDependencies454=== RUN TestClientSharedPathCommittedMidPush455=== PAUSE TestClientSharedPathCommittedMidPush456=== RUN TestPinProtectsFromGC457=== PAUSE TestPinProtectsFromGC458=== RUN TestClientReportsSignatures459=== PAUSE TestClientReportsSignatures460=== RUN TestResolveDBConnectionString461=== PAUSE TestResolveDBConnectionString462=== RUN TestLeadElectsOneAndHandsOver463=== PAUSE TestLeadElectsOneAndHandsOver464=== RUN TestLeadIncumbentWinsAfterRestart4652026-09-22 08:50:55.187 UTC [373] ERROR: relation "goose_db_version" does not exist at character 364662026-09-22 08:50:55.187 UTC [373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4672026/09/22 08:50:55 OK 20241026095416_initial_model.sql (11.04ms)4682026/09/22 08:50:55 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)4692026/09/22 08:50:55 OK 20251218171726_add_pins.sql (3.27ms)4702026/09/22 08:50:55 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)4712026/09/22 08:50:55 OK 20260905000000_add_claims.sql (3.47ms)4722026/09/22 08:50:55 OK 20260920000000_drop_claims.sql (1.91ms)4732026/09/22 08:50:55 goose: successfully migrated database to version: 202609200000004742026/09/22 08:50:55 OK 1_commit_pending_closure.sql (2.04ms)4752026/09/22 08:50:55 OK 2_object_stats_trigger.sql (1.69ms)4762026/09/22 08:50:55 goose: up to current file version: 24772026/09/22 08:50:55 INFO lead: acquired remote=192.0.2.1:12344782026/09/22 08:50:55 INFO lead: released remote=192.0.2.1:12344792026/09/22 08:50:55 INFO lead: acquired remote=192.0.2.1:12344802026/09/22 08:50:55 INFO lead: released remote=192.0.2.1:1234481--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)482=== RUN TestLeadEndsOnShutdown483=== PAUSE TestLeadEndsOnShutdown484=== RUN TestGCAdvisoryLockBlocksConcurrentRun4852026-09-22 08:50:55.968 UTC [384] ERROR: relation "goose_db_version" does not exist at character 364862026-09-22 08:50:55.968 UTC [384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4872026/09/22 08:50:55 OK 20241026095416_initial_model.sql (9.32ms)4882026/09/22 08:50:55 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)4892026/09/22 08:50:55 OK 20251218171726_add_pins.sql (3.9ms)4902026/09/22 08:50:55 OK 20260628120000_add_object_size_and_stats.sql (3.03ms)4912026/09/22 08:50:56 OK 20260905000000_add_claims.sql (3.01ms)4922026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (2.02ms)4932026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000004942026/09/22 08:50:56 OK 1_commit_pending_closure.sql (1.91ms)4952026/09/22 08:50:56 OK 2_object_stats_trigger.sql (825.63µs)4962026/09/22 08:50:56 goose: up to current file version: 2497--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)498=== RUN TestGCBugBareHashReferences499=== PAUSE TestGCBugBareHashReferences500=== RUN TestGCMetrics501=== PAUSE TestGCMetrics502=== RUN TestGCTaskStore_StartNew503=== PAUSE TestGCTaskStore_StartNew504=== RUN TestGCTaskStore_DeduplicateSameParams505=== PAUSE TestGCTaskStore_DeduplicateSameParams506=== RUN TestGCTaskStore_ConflictDifferentParams507=== PAUSE TestGCTaskStore_ConflictDifferentParams508=== RUN TestGCTaskStore_GetEmpty509=== PAUSE TestGCTaskStore_GetEmpty510=== RUN TestGCTaskStore_GetReturnsLatest511=== PAUSE TestGCTaskStore_GetReturnsLatest512=== RUN TestGCTaskStore_CompletedAllowsNewTask513=== PAUSE TestGCTaskStore_CompletedAllowsNewTask514=== RUN TestGCTaskStore_PhaseUpdates515=== PAUSE TestGCTaskStore_PhaseUpdates516=== RUN TestGCTaskStore_Fail517=== PAUSE TestGCTaskStore_Fail518=== RUN TestGracefulShutdownDrainsInflight519=== PAUSE TestGracefulShutdownDrainsInflight520=== RUN TestService_healthCheckHandler521=== PAUSE TestService_healthCheckHandler522=== RUN TestService_readinessHandler523=== PAUSE TestService_readinessHandler524=== RUN TestGenerateLandingPage525=== PAUSE TestGenerateLandingPage526=== RUN TestCacheConfigHandlerMaxNarSize527=== PAUSE TestCacheConfigHandlerMaxNarSize528=== RUN TestCreatePendingClosureRejectsOversizedNAR529=== PAUSE TestCreatePendingClosureRejectsOversizedNAR530=== RUN TestNARDeduplicationMetadataUploadBug531=== PAUSE TestNARDeduplicationMetadataUploadBug532=== RUN TestMetricsInventory533=== PAUSE TestMetricsInventory534=== RUN TestService_NativeMTLS535=== PAUSE TestService_NativeMTLS536=== RUN TestServerTLSConfig537=== PAUSE TestServerTLSConfig538=== RUN TestMultipartCleanup539=== PAUSE TestMultipartCleanup540=== RUN TestObjectStatsTrigger541=== PAUSE TestObjectStatsTrigger542=== RUN TestOrphanedObjectsGC543=== PAUSE TestOrphanedObjectsGC544=== RUN TestOrphanedObjectsGCStressTest545=== PAUSE TestOrphanedObjectsGCStressTest546=== RUN TestResurrectedObjectNotDeleted547=== PAUSE TestResurrectedObjectNotDeleted548=== RUN TestCreatePin_ReservedPins549=== PAUSE TestCreatePin_ReservedPins550=== RUN TestParseSingleRange551=== PAUSE TestParseSingleRange552=== RUN TestIsValidCachePath553=== PAUSE TestIsValidCachePath554=== RUN TestReadProxyNarinfo555=== PAUSE TestReadProxyNarinfo556=== RUN TestReadProxyNarinfoAlreadyDecompressed557=== PAUSE TestReadProxyNarinfoAlreadyDecompressed558=== RUN TestReadProxyNarStreaming559=== PAUSE TestReadProxyNarStreaming560=== RUN TestReadProxy404561=== PAUSE TestReadProxy404562=== RUN TestReadProxyInvalidPath563=== PAUSE TestReadProxyInvalidPath564=== RUN TestReadProxyHead565=== PAUSE TestReadProxyHead566=== RUN TestReadProxyConditionalGet567=== PAUSE TestReadProxyConditionalGet568=== RUN TestReadProxyRootRedirectsToIndexHTML569=== PAUSE TestReadProxyRootRedirectsToIndexHTML570=== RUN TestReadProxyDisabled571=== PAUSE TestReadProxyDisabled572=== RUN TestReadRedirectNar573=== PAUSE TestReadRedirectNar574=== RUN TestReadRedirectKeepsNarinfoProxied575=== PAUSE TestReadRedirectKeepsNarinfoProxied576=== RUN TestReadProxyRangeRequest577=== PAUSE TestReadProxyRangeRequest578=== RUN TestReadRedirectUsesPublicS3URL579=== PAUSE TestReadRedirectUsesPublicS3URL580=== RUN TestRedundantMultipartUpload581=== PAUSE TestRedundantMultipartUpload582=== RUN TestCompleteMultipartUpload_ErrorButObjectExists583=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists584=== RUN TestCompletedNarNotReofferedAcrossClosures585=== PAUSE TestCompletedNarNotReofferedAcrossClosures586=== RUN TestPresignedUploadRegisteredBeforeCommit587=== PAUSE TestPresignedUploadRegisteredBeforeCommit588=== RUN TestService_Rustfstest589=== PAUSE TestService_Rustfstest590=== RUN TestParseSize591=== PAUSE TestParseSize592=== RUN TestSkippedUploadsHandler593=== PAUSE TestSkippedUploadsHandler594=== RUN TestSystemdListenerNotActivated595--- PASS: TestSystemdListenerNotActivated (0.00s)596=== RUN TestWatchdogBeatsWhenHealthy597--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)598=== RUN TestWatchdogSkipsWhenUnhealthy5992026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6002026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6012026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6022026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6032026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6042026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6052026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6062026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6072026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6082026/09/22 08:50:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"609--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)610=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle611=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle612=== RUN TestProxyWriteTimeout613=== PAUSE TestProxyWriteTimeout614=== RUN TestIsValidUploadKey615=== PAUSE TestIsValidUploadKey616=== RUN TestUploadHandlersRejectInvalidKeys617=== PAUSE TestUploadHandlersRejectInvalidKeys618=== RUN TestUploadHandlersRejectOversizedBody619=== PAUSE TestUploadHandlersRejectOversizedBody620=== RUN TestService_cleanupPendingClosuresHandler621=== PAUSE TestService_cleanupPendingClosuresHandler622=== RUN TestService_createPendingClosureHandler623=== PAUSE TestService_createPendingClosureHandler624=== RUN TestService_verifyS3Integrity625=== PAUSE TestService_verifyS3Integrity626=== RUN TestCompleteMultipartUnregistered627=== PAUSE TestCompleteMultipartUnregistered628=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT629=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT630=== CONT TestSkippedUploadsHandler631=== CONT TestReadProxyRangeRequest632=== CONT TestReadProxyRootRedirectsToIndexHTML633=== CONT TestIsValidUploadKey634=== RUN TestIsValidUploadKey/narinfo635=== PAUSE TestIsValidUploadKey/narinfo636=== CONT TestService_cleanupPendingClosuresHandler637=== CONT TestParseSize638--- PASS: TestParseSize (0.00s)639=== CONT TestReadProxyConditionalGet640=== CONT TestService_Rustfstest641=== CONT TestPresignedUploadRegisteredBeforeCommit6422026/09/22 08:50:56 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000643=== CONT TestCompletedNarNotReofferedAcrossClosures644=== CONT TestCompleteMultipartUpload_ErrorButObjectExists645=== CONT TestRedundantMultipartUpload646=== CONT TestReadRedirectUsesPublicS3URL647=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT648=== CONT TestCompleteMultipartUnregistered649=== CONT TestService_verifyS3Integrity650=== CONT TestService_createPendingClosureHandler651=== CONT TestGracefulShutdownDrainsInflight652=== CONT TestReadRedirectKeepsNarinfoProxied653=== CONT TestReadRedirectNar654=== CONT TestReadProxyDisabled655=== CONT TestUploadHandlersRejectOversizedBody656=== CONT TestUploadHandlersRejectInvalidKeys657=== CONT TestOrphanedObjectsGCStressTest6582026/09/22 08:50:56 INFO Starting HTTP server address=127.0.0.1:42399659=== CONT TestService_AuthMiddleware660=== RUN TestIsValidUploadKey/nar_zst661=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info662=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info663=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal664=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal665=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key666=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key667=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key668=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key669=== CONT TestReadProxyHead670=== PAUSE TestIsValidUploadKey/nar_zst671=== RUN TestIsValidUploadKey/nar_xz672=== PAUSE TestIsValidUploadKey/nar_xz673=== RUN TestIsValidUploadKey/nar_plain674=== PAUSE TestIsValidUploadKey/nar_plain675=== RUN TestIsValidUploadKey/listing676=== PAUSE TestIsValidUploadKey/listing677=== RUN TestIsValidUploadKey/build_log678=== PAUSE TestIsValidUploadKey/build_log679=== RUN TestIsValidUploadKey/build_log_home-manager_file680=== PAUSE TestIsValidUploadKey/build_log_home-manager_file6812026/09/22 08:50:56 INFO Shutdown signal received, draining in-flight requests timeout=10s682=== RUN TestIsValidUploadKey/build_log_plus_in_name683=== PAUSE TestIsValidUploadKey/build_log_plus_in_name684=== RUN TestIsValidUploadKey/build_log_question_mark685=== PAUSE TestIsValidUploadKey/build_log_question_mark686=== RUN TestIsValidUploadKey/build_log_equals687=== PAUSE TestIsValidUploadKey/build_log_equals688=== RUN TestIsValidUploadKey/realisation689=== PAUSE TestIsValidUploadKey/realisation690=== RUN TestIsValidUploadKey/realisation_plus_in_output691=== PAUSE TestIsValidUploadKey/realisation_plus_in_output692=== RUN TestIsValidUploadKey/nix-cache-info693=== PAUSE TestIsValidUploadKey/nix-cache-info694=== RUN TestIsValidUploadKey/index.html695--- PASS: TestSkippedUploadsHandler (0.07s)696=== PAUSE TestIsValidUploadKey/index.html697=== CONT TestReadProxyInvalidPath698=== RUN TestIsValidUploadKey/narinfo_key,_nar_type699=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type700=== RUN TestIsValidUploadKey/nar_key,_narinfo_type701=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type702=== RUN TestIsValidUploadKey/listing_key,_narinfo_type703=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type704=== RUN TestIsValidUploadKey/traversal705=== PAUSE TestIsValidUploadKey/traversal706=== RUN TestIsValidUploadKey/traversal_nar707=== PAUSE TestIsValidUploadKey/traversal_nar708=== RUN TestIsValidUploadKey/absolute709=== PAUSE TestIsValidUploadKey/absolute710=== RUN TestIsValidUploadKey/empty_key711=== PAUSE TestIsValidUploadKey/empty_key712=== RUN TestIsValidUploadKey/unknown_type713=== PAUSE TestIsValidUploadKey/unknown_type714=== CONT TestReadProxy4047152026-09-22 08:50:56.349 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367162026-09-22 08:50:56.349 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026-09-22 08:50:56.359 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367182026-09-22 08:50:56.359 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC719=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure720=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure721=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart722=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart723=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts724=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts725=== CONT TestReadProxyNarStreaming7262026-09-22 08:50:56.424 UTC [446] ERROR: relation "goose_db_version" does not exist at character 367272026-09-22 08:50:56.424 UTC [446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7282026-09-22 08:50:56.432 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367292026-09-22 08:50:56.432 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7302026-09-22 08:50:56.432 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367312026-09-22 08:50:56.432 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC732--- PASS: TestGracefulShutdownDrainsInflight (0.21s)733=== CONT TestReadProxyNarinfoAlreadyDecompressed7342026/09/22 08:50:56 OK 20241026095416_initial_model.sql (45.97ms)7352026-09-22 08:50:56.474 UTC [457] ERROR: relation "goose_db_version" does not exist at character 367362026-09-22 08:50:56.474 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7372026/09/22 08:50:56 OK 20241026095416_initial_model.sql (46.3ms)7382026/09/22 08:50:56 OK 20241026095416_initial_model.sql (23.51ms)7392026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.8ms)7402026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.72ms)7412026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (5ms)7422026/09/22 08:50:56 OK 20241026095416_initial_model.sql (47.21ms)7432026/09/22 08:50:56 OK 20251218171726_add_pins.sql (11.86ms)7442026/09/22 08:50:56 OK 20251218171726_add_pins.sql (13.33ms)7452026/09/22 08:50:56 OK 20241026095416_initial_model.sql (33.92ms)7462026/09/22 08:50:56 OK 20251218171726_add_pins.sql (14.11ms)7472026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)7482026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (4.33ms)7492026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (7.42ms)7502026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (9.61ms)7512026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (9.28ms)7522026/09/22 08:50:56 OK 20251218171726_add_pins.sql (8.19ms)7532026/09/22 08:50:56 OK 20260905000000_add_claims.sql (7.06ms)7542026/09/22 08:50:56 OK 20251218171726_add_pins.sql (9.72ms)7552026/09/22 08:50:56 OK 20260905000000_add_claims.sql (8.09ms)7562026/09/22 08:50:56 OK 20241026095416_initial_model.sql (19.08ms)7572026/09/22 08:50:56 OK 20260905000000_add_claims.sql (7.93ms)7582026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (6.39ms)7592026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000007602026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (8.2ms)7612026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (4.97ms)7622026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (6.38ms)7632026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000007642026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (9.26ms)7652026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (5.67ms)7662026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000007672026/09/22 08:50:56 OK 1_commit_pending_closure.sql (5.46ms)7682026-09-22 08:50:56.523 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367692026-09-22 08:50:56.523 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026/09/22 08:50:56 OK 20260905000000_add_claims.sql (6.39ms)7712026-09-22 08:50:56.523 UTC [463] ERROR: relation "goose_db_version" does not exist at character 367722026-09-22 08:50:56.523 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026-09-22 08:50:56.523 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367742026-09-22 08:50:56.523 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026-09-22 08:50:56.523 UTC [462] ERROR: relation "goose_db_version" does not exist at character 367762026-09-22 08:50:56.523 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-09-22 08:50:56.525 UTC [465] ERROR: relation "goose_db_version" does not exist at character 367782026-09-22 08:50:56.525 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026-09-22 08:50:56.525 UTC [464] ERROR: relation "goose_db_version" does not exist at character 367802026-09-22 08:50:56.525 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026-09-22 08:50:56.525 UTC [466] ERROR: relation "goose_db_version" does not exist at character 367822026-09-22 08:50:56.525 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026-09-22 08:50:56.527 UTC [467] ERROR: relation "goose_db_version" does not exist at character 367842026-09-22 08:50:56.527 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7852026/09/22 08:50:56 OK 20251218171726_add_pins.sql (14.59ms)7862026/09/22 08:50:56 OK 2_object_stats_trigger.sql (13.58ms)7872026/09/22 08:50:56 goose: up to current file version: 27882026/09/22 08:50:56 OK 1_commit_pending_closure.sql (16ms)7892026/09/22 08:50:56 OK 1_commit_pending_closure.sql (15.05ms)7902026/09/22 08:50:56 OK 20260905000000_add_claims.sql (15.18ms)7912026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (14.09ms)7922026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000007932026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.42ms)7942026/09/22 08:50:56 goose: up to current file version: 27952026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)7962026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.42ms)7972026/09/22 08:50:56 goose: up to current file version: 27982026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.24ms)7992026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.85ms)8002026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000008012026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.33ms)8022026/09/22 08:50:56 goose: up to current file version: 28032026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.51ms)8042026/09/22 08:50:56 OK 1_commit_pending_closure.sql (5.45ms)8052026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.58ms)8062026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000008072026-09-22 08:50:56.549 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368082026-09-22 08:50:56.549 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026-09-22 08:50:56.549 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368102026-09-22 08:50:56.549 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.7ms)8122026/09/22 08:50:56 goose: up to current file version: 28132026-09-22 08:50:56.550 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368142026-09-22 08:50:56.550 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8152026/09/22 08:50:56 OK 20241026095416_initial_model.sql (13ms)8162026-09-22 08:50:56.551 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368172026-09-22 08:50:56.551 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/09/22 08:50:56 OK 20241026095416_initial_model.sql (13.97ms)8192026-09-22 08:50:56.551 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368202026-09-22 08:50:56.551 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026-09-22 08:50:56.552 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368222026-09-22 08:50:56.552 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026/09/22 08:50:56 OK 20241026095416_initial_model.sql (15.78ms)8242026/09/22 08:50:56 OK 1_commit_pending_closure.sql (5.89ms)8252026/09/22 08:50:56 OK 20241026095416_initial_model.sql (17.07ms)8262026/09/22 08:50:56 OK 20241026095416_initial_model.sql (17.47ms)8272026/09/22 08:50:56 OK 20241026095416_initial_model.sql (16.51ms)8282026/09/22 08:50:56 OK 20241026095416_initial_model.sql (17.14ms)8292026/09/22 08:50:56 OK 20241026095416_initial_model.sql (17.15ms)8302026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (4.04ms)8312026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)8322026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (4ms)8332026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.02ms)8342026/09/22 08:50:56 goose: up to current file version: 28352026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)8362026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)8372026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.12ms)8382026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)8392026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)8402026-09-22 08:50:56.559 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368412026-09-22 08:50:56.559 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026-09-22 08:50:56.560 UTC [475] ERROR: relation "goose_db_version" does not exist at character 368432026-09-22 08:50:56.560 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8442026/09/22 08:50:56 OK 20251218171726_add_pins.sql (4.26ms)8452026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.64ms)8462026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.72ms)8472026/09/22 08:50:56 OK 20251218171726_add_pins.sql (4.84ms)8482026/09/22 08:50:56 OK 20251218171726_add_pins.sql (6ms)8492026/09/22 08:50:56 OK 20251218171726_add_pins.sql (6.19ms)8502026/09/22 08:50:56 OK 20251218171726_add_pins.sql (7.34ms)8512026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)8522026/09/22 08:50:56 OK 20251218171726_add_pins.sql (6.28ms)8532026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)8542026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)8552026-09-22 08:50:56.568 UTC [476] ERROR: relation "goose_db_version" does not exist at character 368562026-09-22 08:50:56.568 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8572026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (6.98ms)8582026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.93ms)8592026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.89ms)8602026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (6.9ms)8612026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.59ms)8622026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.71ms)8632026/09/22 08:50:56 OK 20241026095416_initial_model.sql (15.06ms)8642026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (6.58ms)8652026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (8.26ms)8662026/09/22 08:50:56 OK 20241026095416_initial_model.sql (15.11ms)8672026/09/22 08:50:56 OK 20241026095416_initial_model.sql (12.73ms)8682026/09/22 08:50:56 OK 20241026095416_initial_model.sql (12.92ms)8692026/09/22 08:50:56 OK 20241026095416_initial_model.sql (16.54ms)8702026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.19ms)8712026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (4.1ms)8722026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.56ms)8732026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000008742026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.76ms)8752026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000008762026-09-22 08:50:56.576 UTC [477] ERROR: relation "goose_db_version" does not exist at character 368772026-09-22 08:50:56.576 UTC [477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8782026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.78ms)8792026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000008802026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.01ms)8812026/09/22 08:50:56 OK 20241026095416_initial_model.sql (15.35ms)8822026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)8832026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)8842026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)8852026/09/22 08:50:56 OK 20260905000000_add_claims.sql (6.01ms)8862026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.42ms)8872026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.05ms)8882026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.1ms)8892026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.99ms)8902026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000008912026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.35ms)8922026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.18ms)8932026/09/22 08:50:56 OK 20241026095416_initial_model.sql (11.36ms)8942026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.77ms)8952026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000008962026/09/22 08:50:56 OK 1_commit_pending_closure.sql (4.36ms)8972026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.09ms)8982026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (4.3ms)8992026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.76ms)9002026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009012026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.14ms)9022026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009032026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.05ms)9042026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009052026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.84ms)9062026/09/22 08:50:56 goose: up to current file version: 29072026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.75ms)9082026/09/22 08:50:56 goose: up to current file version: 29092026/09/22 08:50:56 OK 20241026095416_initial_model.sql (14.27ms)9102026/09/22 08:50:56 OK 20251218171726_add_pins.sql (6.09ms)9112026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.45ms)9122026/09/22 08:50:56 OK 20251218171726_add_pins.sql (6.14ms)9132026/09/22 08:50:56 OK 20251218171726_add_pins.sql (6.17ms)9142026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.61ms)9152026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.22ms)9162026/09/22 08:50:56 goose: up to current file version: 29172026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.63ms)9182026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.55ms)9192026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.49ms)9202026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.95ms)9212026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)9222026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)9232026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.4ms)9242026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.38ms)9252026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.09ms)9262026/09/22 08:50:56 goose: up to current file version: 29272026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.34ms)9282026/09/22 08:50:56 goose: up to current file version: 2929--- PASS: TestReadProxyRangeRequest (0.33s)930=== CONT TestReadProxyNarinfo9312026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.46ms)9322026/09/22 08:50:56 goose: up to current file version: 29332026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.1ms)9342026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.78ms)9352026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.69ms)9362026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)9372026/09/22 08:50:56 goose: up to current file version: 29382026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.27ms)9392026/09/22 08:50:56 goose: up to current file version: 29402026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.21ms)9412026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.52ms)9422026/09/22 08:50:56 OK 20241026095416_initial_model.sql (12.83ms)9432026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.12ms)9442026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.37ms)9452026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)9462026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (2.91ms)9472026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009482026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.45ms)9492026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.33ms)9502026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.47ms)9512026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)9522026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (8.21ms)9532026/09/22 08:50:56 OK 20260905000000_add_claims.sql (5.82ms)9542026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.93ms)9552026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)9562026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.19ms)9572026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009582026/09/22 08:50:56 OK 20251218171726_add_pins.sql (4.4ms)9592026/09/22 08:50:56 OK 20241026095416_initial_model.sql (13.12ms)9602026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.1ms)9612026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009622026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.36ms)9632026/09/22 08:50:56 goose: up to current file version: 29642026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.88ms)9652026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009662026/09/22 08:50:56 OK 20260905000000_add_claims.sql (3.93ms)9672026/09/22 08:50:56 OK 20260905000000_add_claims.sql (3.99ms)9682026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.01ms)9692026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009702026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.38ms)9712026/09/22 08:50:56 OK 20260905000000_add_claims.sql (3.34ms)9722026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)9732026/09/22 08:50:56 OK 1_commit_pending_closure.sql (1.98ms)9742026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)9752026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (2.11ms)9762026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009772026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (2.1ms)9782026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009792026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures9802026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.81ms)9812026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.88ms)9822026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.9ms)9832026/09/22 08:50:56 goose: up to current file version: 29842026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.19ms)9852026/09/22 08:50:56 goose: up to current file version: 29862026/09/22 08:50:56 OK 2_object_stats_trigger.sql (1.87ms)9872026/09/22 08:50:56 goose: up to current file version: 29882026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.57ms)9892026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4ms)9902026/09/22 08:50:56 goose: successfully migrated database to version: 202609200000009912026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.51ms)9922026/09/22 08:50:56 OK 20251218171726_add_pins.sql (4.61ms)9932026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.43ms)9942026/09/22 08:50:56 OK 2_object_stats_trigger.sql (1.69ms)9952026/09/22 08:50:56 goose: up to current file version: 29962026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.7ms)9972026/09/22 08:50:56 goose: up to current file version: 29982026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.29ms)9992026/09/22 08:50:56 goose: up to current file version: 210002026/09/22 08:50:56 OK 1_commit_pending_closure.sql (4.69ms)10012026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)10022026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (4.85ms)10032026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000010042026/09/22 08:50:56 OK 2_object_stats_trigger.sql (3.4ms)10052026/09/22 08:50:56 goose: up to current file version: 210062026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.65ms)10072026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.57ms)10082026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.18ms)10092026/09/22 08:50:56 goose: up to current file version: 210102026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.78ms)10112026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000010122026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.7ms)10132026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.43ms)10142026/09/22 08:50:56 goose: up to current file version: 21015--- PASS: TestReadProxyConditionalGet (0.38s)1016=== CONT TestIsValidCachePath1017=== RUN TestIsValidCachePath/narinfo1018=== PAUSE TestIsValidCachePath/narinfo1019=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1020=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1021=== RUN TestIsValidCachePath/nar_zst1022=== PAUSE TestIsValidCachePath/nar_zst1023=== RUN TestIsValidCachePath/nar_xz1024=== PAUSE TestIsValidCachePath/nar_xz1025=== RUN TestIsValidCachePath/nar_bz21026=== PAUSE TestIsValidCachePath/nar_bz21027=== RUN TestIsValidCachePath/nar_uncompressed1028=== PAUSE TestIsValidCachePath/nar_uncompressed1029=== RUN TestIsValidCachePath/ls1030=== PAUSE TestIsValidCachePath/ls1031=== RUN TestIsValidCachePath/log1032=== PAUSE TestIsValidCachePath/log1033=== RUN TestIsValidCachePath/realisation1034=== PAUSE TestIsValidCachePath/realisation1035=== RUN TestIsValidCachePath/nix-cache-info1036=== PAUSE TestIsValidCachePath/nix-cache-info1037=== RUN TestIsValidCachePath/index.html1038=== PAUSE TestIsValidCachePath/index.html1039=== RUN TestIsValidCachePath/traversal_parent1040=== PAUSE TestIsValidCachePath/traversal_parent1041=== RUN TestIsValidCachePath/traversal_in_middle1042=== PAUSE TestIsValidCachePath/traversal_in_middle1043=== RUN TestIsValidCachePath/invalid_char_e1044=== PAUSE TestIsValidCachePath/invalid_char_e1045=== RUN TestIsValidCachePath/invalid_char_u1046=== PAUSE TestIsValidCachePath/invalid_char_u1047=== RUN TestIsValidCachePath/random_path1048=== PAUSE TestIsValidCachePath/random_path1049=== RUN TestIsValidCachePath/empty1050=== PAUSE TestIsValidCachePath/empty1051=== RUN TestIsValidCachePath/leading_slash1052=== PAUSE TestIsValidCachePath/leading_slash1053=== RUN TestIsValidCachePath/wrong_extension1054=== PAUSE TestIsValidCachePath/wrong_extension1055=== RUN TestIsValidCachePath/short_hash1056=== PAUSE TestIsValidCachePath/short_hash1057=== CONT TestParseSingleRange1058=== RUN TestParseSingleRange/none1059=== PAUSE TestParseSingleRange/none1060=== RUN TestParseSingleRange/unknown_unit1061=== PAUSE TestParseSingleRange/unknown_unit1062=== RUN TestParseSingleRange/multi-range_ignored1063=== PAUSE TestParseSingleRange/multi-range_ignored1064=== RUN TestParseSingleRange/malformed_no_dash1065=== PAUSE TestParseSingleRange/malformed_no_dash1066=== RUN TestParseSingleRange/malformed_both_empty1067=== PAUSE TestParseSingleRange/malformed_both_empty1068=== RUN TestParseSingleRange/malformed_end_before_start1069=== PAUSE TestParseSingleRange/malformed_end_before_start1070=== RUN TestParseSingleRange/closed1071=== PAUSE TestParseSingleRange/closed1072=== RUN TestParseSingleRange/open-ended1073=== PAUSE TestParseSingleRange/open-ended1074=== RUN TestParseSingleRange/end_clamped_to_size1075=== PAUSE TestParseSingleRange/end_clamped_to_size1076=== RUN TestParseSingleRange/suffix1077=== PAUSE TestParseSingleRange/suffix1078=== RUN TestParseSingleRange/suffix_exceeds_size1079=== PAUSE TestParseSingleRange/suffix_exceeds_size1080=== RUN TestParseSingleRange/single_byte1081=== PAUSE TestParseSingleRange/single_byte1082=== RUN TestParseSingleRange/start_past_EOF1083=== PAUSE TestParseSingleRange/start_past_EOF1084=== RUN TestParseSingleRange/start_far_past_EOF1085=== PAUSE TestParseSingleRange/start_far_past_EOF1086=== CONT TestCreatePin_ReservedPins1087--- PASS: TestService_Rustfstest (0.39s)1088=== CONT TestResurrectedObjectNotDeleted10892026-09-22 08:50:56.652 UTC [482] ERROR: relation "goose_db_version" does not exist at character 3610902026-09-22 08:50:56.652 UTC [482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026/09/22 08:50:56 OK 20241026095416_initial_model.sql (17.33ms)10922026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (3ms)10932026/09/22 08:50:56 OK 20251218171726_add_pins.sql (3.99ms)1094--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.42s)1095=== CONT TestGCTaskStore_DeduplicateSameParams1096--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1097=== CONT TestGCTaskStore_Fail1098--- PASS: TestGCTaskStore_Fail (0.00s)1099=== CONT TestGCTaskStore_PhaseUpdates1100--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1101=== CONT TestGCTaskStore_CompletedAllowsNewTask1102--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1103=== CONT TestGCTaskStore_GetReturnsLatest1104--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1105=== CONT TestGCTaskStore_GetEmpty1106--- PASS: TestGCTaskStore_GetEmpty (0.00s)1107=== CONT TestGCTaskStore_ConflictDifferentParams1108--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1109=== CONT TestPinProtectsFromGC11102026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)11112026/09/22 08:50:56 OK 20260905000000_add_claims.sql (3.89ms)11122026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (2.84ms)11132026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000011142026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.11ms)11152026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.13ms)11162026/09/22 08:50:56 goose: up to current file version: 211172026/09/22 08:50:56 INFO Received cleanup request method=DELETE path=/api/pending_closures11182026/09/22 08:50:56 INFO Aborted multipart uploads count=011192026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures11202026-09-22 08:50:56.725 UTC [487] ERROR: relation "goose_db_version" does not exist at character 3611212026-09-22 08:50:56.725 UTC [487] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/09/22 08:50:56 INFO Received cleanup request method=DELETE path=/api/pending_closures11232026/09/22 08:50:56 INFO Aborted multipart uploads count=111242026/09/22 08:50:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11252026-09-22 08:50:56.737 UTC [457] ERROR: Closure does not exist: id=111262026-09-22 08:50:56.737 UTC [457] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11272026-09-22 08:50:56.737 UTC [457] STATEMENT: -- name: CommitPendingClosure :exec1128 SELECT commit_pending_closure($1::bigint)1129 1130--- PASS: TestService_cleanupPendingClosuresHandler (0.48s)1131=== CONT TestLeadEndsOnShutdown11322026/09/22 08:50:56 OK 20241026095416_initial_model.sql (11.33ms)11332026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)11342026/09/22 08:50:56 OK 20251218171726_add_pins.sql (2.57ms)11352026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)11362026-09-22 08:50:56.756 UTC [490] ERROR: relation "goose_db_version" does not exist at character 3611372026-09-22 08:50:56.756 UTC [490] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11382026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.47ms)11392026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.15ms)11402026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000011412026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.08ms)11422026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.15ms)11432026/09/22 08:50:56 goose: up to current file version: 21144--- PASS: TestReadRedirectUsesPublicS3URL (0.51s)1145=== CONT TestLeadElectsOneAndHandsOver11462026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures11472026/09/22 08:50:56 OK 20241026095416_initial_model.sql (11.75ms)11482026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)11492026/09/22 08:50:56 OK 20251218171726_add_pins.sql (3.5ms)11502026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)11512026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.27ms)11522026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.47ms)11532026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000011542026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.5ms)11552026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.01ms)11562026/09/22 08:50:56 goose: up to current file version: 21157--- PASS: TestReadProxyDisabled (0.54s)1158=== CONT TestGCTaskStore_StartNew1159--- PASS: TestGCTaskStore_StartNew (0.00s)1160=== CONT TestResolveDBConnectionString1161=== RUN TestResolveDBConnectionString/flag_wins1162=== PAUSE TestResolveDBConnectionString/flag_wins1163=== RUN TestResolveDBConnectionString/file_when_flag_empty1164=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1165=== RUN TestResolveDBConnectionString/missing_file_is_an_error1166=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1167=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1168=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1169=== RUN TestResolveDBConnectionString/nothing_configured1170=== PAUSE TestResolveDBConnectionString/nothing_configured1171=== CONT TestGCMetrics11722026-09-22 08:50:56.810 UTC [494] ERROR: relation "goose_db_version" does not exist at character 3611732026-09-22 08:50:56.810 UTC [494] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11742026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures11752026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures11762026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures11772026/09/22 08:50:56 OK 20241026095416_initial_model.sql (19.51ms)11782026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)11792026/09/22 08:50:56 OK 20251218171726_add_pins.sql (3.83ms)11802026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.24ms)11812026-09-22 08:50:56.849 UTC [496] ERROR: relation "goose_db_version" does not exist at character 3611822026-09-22 08:50:56.849 UTC [496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11832026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.1ms)11842026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.73ms)11852026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000011862026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.95ms)11872026/09/22 08:50:56 OK 2_object_stats_trigger.sql (1.77ms)11882026/09/22 08:50:56 goose: up to current file version: 211892026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures11902026/09/22 08:50:56 OK 20241026095416_initial_model.sql (10.63ms)11912026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)11922026/09/22 08:50:56 OK 20251218171726_add_pins.sql (3.25ms)1193--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.61s)1194=== CONT TestClientReportsSignatures11952026-09-22 08:50:56.874 UTC [497] ERROR: relation "goose_db_version" does not exist at character 3611962026-09-22 08:50:56.874 UTC [497] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11972026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)11982026/09/22 08:50:56 OK 20260905000000_add_claims.sql (3.63ms)11992026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (2.03ms)12002026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000012012026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.05ms)12022026/09/22 08:50:56 OK 2_object_stats_trigger.sql (947.47µs)12032026/09/22 08:50:56 goose: up to current file version: 212042026/09/22 08:50:56 OK 20241026095416_initial_model.sql (10.63ms)12052026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)12062026/09/22 08:50:56 OK 20251218171726_add_pins.sql (5.55ms)12072026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)12082026/09/22 08:50:56 OK 20260905000000_add_claims.sql (3.98ms)1209--- PASS: TestReadRedirectKeepsNarinfoProxied (0.65s)1210=== CONT TestGCBugBareHashReferences12112026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.34ms)12122026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000012132026/09/22 08:50:56 OK 1_commit_pending_closure.sql (2.84ms)12142026/09/22 08:50:56 OK 2_object_stats_trigger.sql (2.56ms)12152026/09/22 08:50:56 goose: up to current file version: 212162026/09/22 08:50:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12172026/09/22 08:50:56 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1218--- PASS: TestCompleteMultipartUnregistered (0.67s)1219=== CONT TestCacheStatsHandler12202026-09-22 08:50:56.946 UTC [504] ERROR: relation "goose_db_version" does not exist at character 3612212026-09-22 08:50:56.946 UTC [504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures12232026/09/22 08:50:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34995/oidc12242026/09/22 08:50:56 OK 20241026095416_initial_model.sql (13.97ms)12252026/09/22 08:50:56 OK 20251210153512_drop_unused_gin_index.sql (7.51ms)12262026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures12272026/09/22 08:50:56 OK 20251218171726_add_pins.sql (4.91ms)12282026/09/22 08:50:56 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)12292026-09-22 08:50:56.987 UTC [507] ERROR: relation "goose_db_version" does not exist at character 3612302026-09-22 08:50:56.987 UTC [507] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12312026/09/22 08:50:56 INFO Received uploads request method=POST path=/api/pending_closures12322026/09/22 08:50:56 OK 20260905000000_add_claims.sql (4.8ms)12332026/09/22 08:50:56 OK 20260920000000_drop_claims.sql (3.14ms)12342026/09/22 08:50:56 goose: successfully migrated database to version: 2026092000000012352026/09/22 08:50:56 OK 1_commit_pending_closure.sql (3.03ms)12362026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.95ms)12372026/09/22 08:50:57 goose: up to current file version: 212382026-09-22 08:50:57.001 UTC [508] ERROR: relation "goose_db_version" does not exist at character 3612392026-09-22 08:50:57.001 UTC [508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.05ms)12412026/09/22 08:50:57 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12422026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures12432026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)1244--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.75s)1245=== CONT TestProxyWriteTimeout1246=== RUN TestProxyWriteTimeout/narinfo1247=== PAUSE TestProxyWriteTimeout/narinfo1248=== RUN TestProxyWriteTimeout/1_GiB_nar1249=== PAUSE TestProxyWriteTimeout/1_GiB_nar1250=== RUN TestProxyWriteTimeout/10_GiB_nar1251=== PAUSE TestProxyWriteTimeout/10_GiB_nar1252=== RUN TestProxyWriteTimeout/unknown_size1253=== PAUSE TestProxyWriteTimeout/unknown_size1254=== CONT TestClientSharedPathCommittedMidPush12552026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.46ms)12562026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)12572026/09/22 08:50:57 OK 20241026095416_initial_model.sql (10.17ms)12582026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)12592026/09/22 08:50:57 OK 20260905000000_add_claims.sql (3.4ms)12602026/09/22 08:50:57 OK 20251218171726_add_pins.sql (2.79ms)12612026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.29ms)12622026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000012632026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)12642026/09/22 08:50:57 OK 1_commit_pending_closure.sql (4.14ms)12652026-09-22 08:50:57.029 UTC [511] ERROR: relation "goose_db_version" does not exist at character 3612662026-09-22 08:50:57.029 UTC [511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12672026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.41ms)12682026/09/22 08:50:57 goose: up to current file version: 212692026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.69ms)1270--- PASS: TestReadProxyHead (0.77s)1271=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12722026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (4.49ms)12732026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000012742026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.05ms)12752026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.93ms)12762026/09/22 08:50:57 goose: up to current file version: 212772026/09/22 08:50:57 OK 20241026095416_initial_model.sql (11.13ms)12782026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)12792026/09/22 08:50:57 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1280--- PASS: TestService_AuthMiddleware (0.79s)1281=== CONT TestClientWithDependencies12822026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.9ms)12832026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)12842026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.2ms)12852026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.19ms)12862026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000012872026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.21ms)12882026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.24ms)12892026/09/22 08:50:57 goose: up to current file version: 212902026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures12912026-09-22 08:50:57.086 UTC [516] ERROR: relation "goose_db_version" does not exist at character 3612922026-09-22 08:50:57.086 UTC [516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12932026-09-22 08:50:57.117 UTC [517] ERROR: relation "goose_db_version" does not exist at character 3612942026-09-22 08:50:57.117 UTC [517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12952026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.98ms)12962026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)12972026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.33ms)12982026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)12992026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.16ms)13002026/09/22 08:50:57 OK 20241026095416_initial_model.sql (10.01ms)13012026-09-22 08:50:57.134 UTC [518] ERROR: relation "goose_db_version" does not exist at character 3613022026-09-22 08:50:57.134 UTC [518] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13032026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13042026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)13052026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.9ms)13062026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000013072026/09/22 08:50:57 OK 1_commit_pending_closure.sql (2.67ms)13082026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.15ms)13092026/09/22 08:50:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yzk5OWQ4NDUtMDg0My00NGU1LTllNWMtYWJmMzdmYzI2YTI4LjhhNGEyOWQ3LTcxNmUtNDI1My05M2JjLTk3OGViYzUwZmU4OHgxNzkwMDY3MDU3MTA0NDg3NzUy13102026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.68ms)13112026/09/22 08:50:57 goose: up to current file version: 213122026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)13132026/09/22 08:50:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yzk5OWQ4NDUtMDg0My00NGU1LTllNWMtYWJmMzdmYzI2YTI4LjhhNGEyOWQ3LTcxNmUtNDI1My05M2JjLTk3OGViYzUwZmU4OHgxNzkwMDY3MDU3MTA0NDg3NzUy parts=11314--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.88s)1315=== CONT TestMetricsInventory13162026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.42ms)13172026/09/22 08:50:57 OK 20241026095416_initial_model.sql (10.99ms)13182026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.59ms)13192026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000013202026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)13212026/09/22 08:50:57 OK 1_commit_pending_closure.sql (2.4ms)1322--- PASS: TestReadRedirectNar (0.89s)1323=== CONT TestClientMultipleUploads13242026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.94ms)13252026/09/22 08:50:57 goose: up to current file version: 213262026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.02ms)13272026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)13282026/09/22 08:50:57 OK 20260905000000_add_claims.sql (3.92ms)13292026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.87ms)13302026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000013312026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.23ms)13322026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.34ms)13332026/09/22 08:50:57 goose: up to current file version: 21334--- PASS: TestReadProxyInvalidPath (0.84s)1335=== CONT TestOrphanedObjectsGC1336--- PASS: TestReadProxy404 (0.87s)1337=== CONT TestClientIntegration13382026-09-22 08:50:57.221 UTC [527] ERROR: relation "goose_db_version" does not exist at character 3613392026-09-22 08:50:57.221 UTC [527] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13402026-09-22 08:50:57.230 UTC [528] ERROR: relation "goose_db_version" does not exist at character 3613412026-09-22 08:50:57.230 UTC [528] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13422026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1343--- PASS: TestReadProxyNarStreaming (0.82s)1344=== CONT TestObjectStatsTrigger13452026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.41ms)13462026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.12ms)13472026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)13482026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)13492026-09-22 08:50:57.251 UTC [531] ERROR: relation "goose_db_version" does not exist at character 3613502026-09-22 08:50:57.251 UTC [531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13512026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4ms)13522026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.71ms)13532026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)13542026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (6.44ms)13552026/09/22 08:50:57 OK 20260905000000_add_claims.sql (5.45ms)13562026/09/22 08:50:57 OK 20260905000000_add_claims.sql (5.03ms)13572026/09/22 08:50:57 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Yzk5OWQ4NDUtMDg0My00NGU1LTllNWMtYWJmMzdmYzI2YTI4LmI5ZDNhMDkzLWMxNGMtNGRlZC04NDFmLTFiYmRlZjcxOGZmZngxNzkwMDY3MDU2NjEzMjU4NDEy parts=1213582026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.32ms)13592026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000013602026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.65ms)13612026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000013622026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures13632026/09/22 08:50:57 OK 20241026095416_initial_model.sql (13.08ms)13642026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.55ms)13652026/09/22 08:50:57 OK 1_commit_pending_closure.sql (4.67ms)1366--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.01s)1367=== CONT TestClientErrorHandling1368=== RUN TestClientErrorHandling/InvalidStorePath1369=== PAUSE TestClientErrorHandling/InvalidStorePath1370=== RUN TestClientErrorHandling/InvalidAuthToken1371=== PAUSE TestClientErrorHandling/InvalidAuthToken1372=== RUN TestClientErrorHandling/ServerNotAvailable1373=== PAUSE TestClientErrorHandling/ServerNotAvailable1374=== CONT TestMultipartCleanup13752026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)13762026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.47ms)13772026/09/22 08:50:57 goose: up to current file version: 213782026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.3ms)13792026/09/22 08:50:57 goose: up to current file version: 21380--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.81s)1381=== CONT TestClientCADerivations13822026-09-22 08:50:57.280 UTC [556] ERROR: relation "goose_db_version" does not exist at character 3613832026-09-22 08:50:57.280 UTC [556] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13842026/09/22 08:50:57 OK 20251218171726_add_pins.sql (5.06ms)13852026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)13862026/09/22 08:50:57 OK 20260905000000_add_claims.sql (3.92ms)13872026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (4.32ms)13882026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000013892026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13902026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.65ms)13912026/09/22 08:50:57 OK 20241026095416_initial_model.sql (13.28ms)13922026/09/22 08:50:57 OK 2_object_stats_trigger.sql (3.4ms)13932026/09/22 08:50:57 goose: up to current file version: 213942026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (4.08ms)13952026/09/22 08:50:57 OK 20251218171726_add_pins.sql (9.72ms)1396--- PASS: TestReadProxyNarinfo (0.73s)1397=== CONT TestServerTLSConfig1398=== RUN TestServerTLSConfig/no_client_CA1399=== PAUSE TestServerTLSConfig/no_client_CA1400=== RUN TestServerTLSConfig/missing_CA_file1401=== PAUSE TestServerTLSConfig/missing_CA_file1402=== RUN TestServerTLSConfig/not_a_PEM_file1403=== PAUSE TestServerTLSConfig/not_a_PEM_file1404=== CONT TestService_AuthMiddleware_OIDC14052026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)14062026/09/22 08:50:57 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Yzk5OWQ4NDUtMDg0My00NGU1LTllNWMtYWJmMzdmYzI2YTI4LmVkYzMxMThkLWIyYjAtNDYzMC04MzNlLTI3NWE3YTliMTQzZXgxNzkwMDY3MDU2Nzc5MDUyNDM3 parts=1014072026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14082026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.92ms)14092026/09/22 08:50:57 INFO Completed upload id=114102026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.78ms)14112026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000014122026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures14132026-09-22 08:50:57.329 UTC [561] ERROR: relation "goose_db_version" does not exist at character 3614142026-09-22 08:50:57.329 UTC [561] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures14162026/09/22 08:50:57 OK 1_commit_pending_closure.sql (14.65ms)14172026/09/22 08:50:57 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14182026/09/22 08:50:57 WARN Found objects in DB but missing from S3, will re-upload count=114192026/09/22 08:50:57 OK 2_object_stats_trigger.sql (3.12ms)14202026/09/22 08:50:57 goose: up to current file version: 21421--- PASS: TestService_verifyS3Integrity (1.09s)1422=== CONT TestService_NativeMTLS14232026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14242026/09/22 08:50:57 OK 20241026095416_initial_model.sql (9.53ms)14252026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)14262026-09-22 08:50:57.358 UTC [563] ERROR: relation "goose_db_version" does not exist at character 3614272026-09-22 08:50:57.358 UTC [563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14282026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.23ms)14292026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)14302026-09-22 08:50:57.365 UTC [565] ERROR: relation "goose_db_version" does not exist at character 3614312026-09-22 08:50:57.365 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14322026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.19ms)14332026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.78ms)14342026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000014352026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.06ms)14362026/09/22 08:50:57 OK 20241026095416_initial_model.sql (11.83ms)14372026/09/22 08:50:57 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Yzk5OWQ4NDUtMDg0My00NGU1LTllNWMtYWJmMzdmYzI2YTI4Ljc0NmVlZjQ5LTM5ZTktNGYxYy1iNDY1LWRhNWMyMTViY2M4ZngxNzkwMDY3MDU2ODQyMDkwNzI2 parts=1014382026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14392026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.55ms)14402026/09/22 08:50:57 goose: up to current file version: 214412026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)14422026/09/22 08:50:57 INFO Completed upload id=114432026/09/22 08:50:57 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014442026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.04ms)14452026/09/22 08:50:57 OK 20241026095416_initial_model.sql (11.77ms)14462026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures14472026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)14482026/09/22 08:50:57 INFO Starting cleanup of old closures method=DELETE path=/api/closures14492026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)14502026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.85ms)14512026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.45ms)14522026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.22ms)14532026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000014542026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)1455--- PASS: TestResurrectedObjectNotDeleted (0.75s)14562026/09/22 08:50:57 INFO Aborted multipart uploads count=01457=== CONT TestCacheConfigHandler1458=== RUN TestCacheConfigHandler/full_config,_no_issuer1459=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1460=== RUN TestCacheConfigHandler/no_cache_url_configured1461=== PAUSE TestCacheConfigHandler/no_cache_url_configured1462=== RUN TestCacheConfigHandler/no_signing_keys1463=== PAUSE TestCacheConfigHandler/no_signing_keys1464=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1465=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1466=== CONT TestService_RequireScope_OIDC14672026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.24ms)14682026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.97ms)14692026/09/22 08:50:57 goose: up to current file version: 214702026/09/22 08:50:57 OK 20260905000000_add_claims.sql (5.04ms)14712026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.89ms)14722026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000014732026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.15ms)14742026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.1ms)14752026/09/22 08:50:57 goose: up to current file version: 214762026/09/22 08:50:57 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=014772026/09/22 08:50:57 INFO Vacuumed table table=pending_closures14782026/09/22 08:50:57 INFO lead: acquired remote=192.0.2.1:123414792026/09/22 08:50:57 INFO lead: released remote=192.0.2.1:12341480--- PASS: TestLeadEndsOnShutdown (0.68s)1481=== CONT TestService_ReadScope_PublicByDefault14822026/09/22 08:50:57 INFO Vacuumed table table=pending_objects14832026/09/22 08:50:57 INFO Vacuumed table table=multipart_uploads14842026/09/22 08:50:57 INFO Vacuumed table table=closures14852026/09/22 08:50:57 INFO Vacuumed table table=objects14862026-09-22 08:50:57.424 UTC [577] ERROR: relation "goose_db_version" does not exist at character 3614872026-09-22 08:50:57.424 UTC [577] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14882026/09/22 08:50:57 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001489--- PASS: TestService_createPendingClosureHandler (1.18s)1490=== CONT TestService_readinessHandler14912026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.06ms)14922026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)14932026/09/22 08:50:57 INFO lead: acquired remote=192.0.2.1:123414942026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.39ms)14952026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)14962026/09/22 08:50:57 OK 20260905000000_add_claims.sql (5.15ms)14972026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.4ms)14982026/09/22 08:50:57 goose: successfully migrated database to version: 202609200000001499=== NAME TestPinProtectsFromGC1500 client_integration_test.go:732: Pinned store path: /build/TestPinProtectsFromGC3933145204/001/store/3sfjfyzwvg3gbvacn6pb6bsys3ig6v1z-pinned-file.txt1501 client_integration_test.go:733: Unpinned store path: /build/TestPinProtectsFromGC3933145204/001/store/gam60fml4z1yhh8mzdzhganjp2mrvf13-unpinned-file.txt15022026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.27ms)15032026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.56ms)15042026/09/22 08:50:57 goose: up to current file version: 215052026-09-22 08:50:57.479 UTC [608] ERROR: relation "goose_db_version" does not exist at character 3615062026-09-22 08:50:57.479 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15072026/09/22 08:50:57 INFO Aborted multipart uploads count=015082026/09/22 08:50:57 WARN Force mode enabled - objects will be deleted immediately without grace period15092026/09/22 08:50:57 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=015102026/09/22 08:50:57 INFO Vacuumed table table=pending_closures15112026/09/22 08:50:57 INFO Vacuumed table table=pending_objects15122026/09/22 08:50:57 INFO Vacuumed table table=multipart_uploads15132026/09/22 08:50:57 INFO Vacuumed table table=closures15142026/09/22 08:50:57 INFO Vacuumed table table=objects1515--- PASS: TestGCMetrics (0.70s)1516=== CONT TestCacheConfigHandlerMaxNarSize1517--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1518=== CONT TestCreatePendingClosureRejectsOversizedNAR15192026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures1520--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1521=== CONT TestNARDeduplicationMetadataUploadBug15222026/09/22 08:50:57 OK 20241026095416_initial_model.sql (18.75ms)15232026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)15242026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.19ms)15252026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)15262026/09/22 08:50:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37167/oidc15272026/09/22 08:50:57 OK 20260905000000_add_claims.sql (5.19ms)15282026-09-22 08:50:57.525 UTC [631] ERROR: relation "goose_db_version" does not exist at character 3615292026-09-22 08:50:57.525 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15302026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.1ms)15312026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000015322026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.3ms)15332026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.3ms)15342026/09/22 08:50:57 goose: up to current file version: 215352026/09/22 08:50:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15362026/09/22 08:50:57 OK 20241026095416_initial_model.sql (11.54ms)15372026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)15382026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.41ms)15392026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)15402026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.01ms)15412026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.93ms)15422026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000015432026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.11ms)15442026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.91ms)15452026/09/22 08:50:57 goose: up to current file version: 215462026-09-22 08:50:57.575 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3615472026-09-22 08:50:57.575 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15482026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures1549=== NAME TestClientReportsSignatures1550 client_integration_test.go:833: unexpected error: getting path info: command failed: nix --extra-experimental-features nix-command path-info --recursive --json -- /nix/store/bhhbf9j407j8miyb8qlwhiblfpkj70xz-nix-2.34.81551 stderr: warning: you don't have Internet access; disabling some network-dependent features1552 don't know how to build these paths:1553 /nix/store/bhhbf9j407j8miyb8qlwhiblfpkj70xz-nix-2.34.81554 error: path '/nix/store/bhhbf9j407j8miyb8qlwhiblfpkj70xz-nix-2.34.8' is not valid1555 1556 error: exit status 11557 1558--- FAIL: TestClientReportsSignatures (0.71s)1559=== CONT TestGenerateLandingPage15602026/09/22 08:50:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44627/oidc15612026/09/22 08:50:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15622026/09/22 08:50:57 INFO Uploading 3sfjfyzwvg3gbvacn6pb6bsys3ig6v1z-pinned-file.txt (128B)1563--- PASS: TestGenerateLandingPage (0.00s)1564=== CONT TestService_healthCheckHandler15652026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1566--- PASS: TestCacheStatsHandler (0.66s)1567=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15682026/09/22 08:50:57 OK 20241026095416_initial_model.sql (10.08ms)15692026/09/22 08:50:57 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15702026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)15712026-09-22 08:50:57.596 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3615722026-09-22 08:50:57.596 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15732026/09/22 08:50:57 WARN Failed to register uploaded object key=3sfjfyzwvg3gbvacn6pb6bsys3ig6v1z.ls error="server returned 404: 404 page not found\n"15742026/09/22 08:50:57 INFO lead: released remote=192.0.2.1:123415752026/09/22 08:50:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15762026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.72ms)15772026/09/22 08:50:57 INFO Signed narinfos id=1 count=115782026/09/22 08:50:57 INFO Uploading 1 narinfos15792026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15802026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (5.55ms)15812026/09/22 08:50:57 WARN Failed to register uploaded object key=3sfjfyzwvg3gbvacn6pb6bsys3ig6v1z.narinfo error="server returned 404: 404 page not found\n"15822026/09/22 08:50:57 OK 20260905000000_add_claims.sql (5.19ms)15832026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.96ms)15842026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000015852026/09/22 08:50:57 INFO Completed upload id=115862026/09/22 08:50:57 INFO Upload complete. (113ms)15872026/09/22 08:50:57 OK 20241026095416_initial_model.sql (13.63ms)15882026/09/22 08:50:57 OK 1_commit_pending_closure.sql (4.71ms)15892026/09/22 08:50:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Yzk5OWQ4NDUtMDg0My00NGU1LTllNWMtYWJmMzdmYzI2YTI4LmRkNDAwMjVlLTRjYmMtNDMzMC1iNmIzLTU0YmNlMzJiZjZhNXgxNzkwMDY3MDU2OTY4MDkyNzQ0 parts=1215902026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.83ms)15912026/09/22 08:50:57 goose: up to current file version: 215922026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (3.98ms)1593--- PASS: TestRedundantMultipartUpload (1.36s)1594=== CONT TestService_AuthMiddleware_MTLSProxyHeader15952026/09/22 08:50:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15962026/09/22 08:50:57 WARN Refused reserved pin name=worker-x86_64-linux15972026/09/22 08:50:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15982026/09/22 08:50:57 INFO Received create pin request method=POST path=/api/pins/my-app15992026/09/22 08:50:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16002026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.56ms)1601--- PASS: TestCreatePin_ReservedPins (0.98s)1602=== CONT TestService_ReadAuthMiddleware16032026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (12.59ms)16042026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.06ms)16052026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.42ms)16062026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000016072026/09/22 08:50:57 INFO lead: acquired remote=192.0.2.1:123416082026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.18ms)16092026/09/22 08:50:57 INFO lead: released remote=192.0.2.1:123416102026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.53ms)16112026/09/22 08:50:57 goose: up to current file version: 21612--- PASS: TestLeadElectsOneAndHandsOver (0.89s)1613=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16142026/09/22 08:50:57 INFO Received uploads request method=POST path=/1615=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16162026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/1617=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16182026/09/22 08:50:57 INFO Received request for more parts method=POST path=/1619=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16202026/09/22 08:50:57 INFO Received uploads request method=POST path=/1621--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1622 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1623 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1624 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1625 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1626=== CONT TestIsValidUploadKey/narinfo1627=== CONT TestIsValidUploadKey/realisation_plus_in_output1628=== CONT TestIsValidUploadKey/unknown_type1629=== CONT TestIsValidUploadKey/empty_key1630=== CONT TestIsValidUploadKey/absolute1631=== CONT TestIsValidUploadKey/traversal_nar1632=== CONT TestIsValidUploadKey/traversal1633=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1634=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1635=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1636=== CONT TestIsValidUploadKey/index.html1637=== CONT TestIsValidUploadKey/nix-cache-info1638=== CONT TestIsValidUploadKey/build_log_home-manager_file1639=== CONT TestIsValidUploadKey/realisation1640=== CONT TestIsValidUploadKey/build_log_equals1641=== CONT TestIsValidUploadKey/build_log_question_mark1642=== CONT TestIsValidUploadKey/build_log_plus_in_name1643=== CONT TestIsValidUploadKey/nar_plain1644=== CONT TestIsValidUploadKey/build_log1645=== CONT TestIsValidUploadKey/listing1646=== CONT TestIsValidUploadKey/nar_xz1647=== CONT TestIsValidUploadKey/nar_zst1648--- PASS: TestIsValidUploadKey (0.07s)1649 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1650 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1651 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1652 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1653 --- PASS: TestIsValidUploadKey/absolute (0.00s)1654 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1655 --- PASS: TestIsValidUploadKey/traversal (0.00s)1656 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1657 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1658 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1659 --- PASS: TestIsValidUploadKey/index.html (0.00s)1660 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1661 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1662 --- PASS: TestIsValidUploadKey/realisation (0.00s)1663 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1664 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1665 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1666 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1667 --- PASS: TestIsValidUploadKey/build_log (0.00s)1668 --- PASS: TestIsValidUploadKey/listing (0.00s)1669 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1670 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1671=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16722026/09/22 08:50:57 INFO Received uploads request method=POST path=/16732026-09-22 08:50:57.665 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3616742026-09-22 08:50:57.665 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16752026-09-22 08:50:57.672 UTC [738] ERROR: relation "goose_db_version" does not exist at character 3616762026-09-22 08:50:57.672 UTC [738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16772026-09-22 08:50:57.673 UTC [739] ERROR: relation "goose_db_version" does not exist at character 3616782026-09-22 08:50:57.673 UTC [739] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16792026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures16802026/09/22 08:50:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16812026/09/22 08:50:57 OK 20241026095416_initial_model.sql (13.06ms)16822026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)16832026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.29ms)16842026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.86ms)16852026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.85ms)16862026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)16872026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)16882026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)16892026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.5ms)16902026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.42ms)16912026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.01ms)16922026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)16932026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.98ms)16942026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000016952026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (6.28ms)16962026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.2ms)16972026/09/22 08:50:57 OK 1_commit_pending_closure.sql (2.86ms)16982026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.87ms)16992026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000017002026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.53ms)17012026-09-22 08:50:57.711 UTC [775] ERROR: relation "goose_db_version" does not exist at character 3617022026-09-22 08:50:57.711 UTC [775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17032026/09/22 08:50:57 OK 2_object_stats_trigger.sql (2.93ms)17042026/09/22 08:50:57 goose: up to current file version: 217052026/09/22 08:50:57 OK 1_commit_pending_closure.sql (3.99ms)17062026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (4.72ms)17072026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000017082026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures17092026/09/22 08:50:57 OK 2_object_stats_trigger.sql (7.93ms)17102026/09/22 08:50:57 goose: up to current file version: 217112026/09/22 08:50:57 OK 1_commit_pending_closure.sql (8.06ms)17122026/09/22 08:50:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17132026/09/22 08:50:57 INFO Uploading gam60fml4z1yhh8mzdzhganjp2mrvf13-unpinned-file.txt (128B)17142026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.47ms)17152026/09/22 08:50:57 goose: up to current file version: 217162026/09/22 08:50:57 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17172026-09-22 08:50:57.735 UTC [811] ERROR: relation "goose_db_version" does not exist at character 3617182026-09-22 08:50:57.735 UTC [811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17192026/09/22 08:50:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17202026/09/22 08:50:57 OK 20241026095416_initial_model.sql (11.63ms)17212026/09/22 08:50:57 WARN Failed to register uploaded object key=gam60fml4z1yhh8mzdzhganjp2mrvf13.ls error="server returned 404: 404 page not found\n"17222026/09/22 08:50:57 INFO Signed narinfos id=2 count=117232026/09/22 08:50:57 INFO Uploading 1 narinfos17242026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)17252026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.08ms)17262026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17272026/09/22 08:50:57 WARN Failed to register uploaded object key=gam60fml4z1yhh8mzdzhganjp2mrvf13.narinfo error="server returned 404: 404 page not found\n"17282026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (3.42ms)17292026/09/22 08:50:57 INFO Completed upload id=217302026/09/22 08:50:57 INFO Upload complete. (94ms)17312026/09/22 08:50:57 OK 20260905000000_add_claims.sql (3.97ms)17322026/09/22 08:50:57 OK 20241026095416_initial_model.sql (9.76ms)17332026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.42ms)17342026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000017352026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)17362026/09/22 08:50:57 OK 1_commit_pending_closure.sql (2.18ms)1737--- PASS: TestMetricsInventory (0.61s)1738=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17392026/09/22 08:50:57 INFO Received request for more parts method=POST path=/17402026/09/22 08:50:57 OK 20251218171726_add_pins.sql (2.67ms)17412026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.29ms)17422026/09/22 08:50:57 goose: up to current file version: 217432026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)17442026/09/22 08:50:57 OK 20260905000000_add_claims.sql (3.58ms)17452026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.12ms)17462026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000017472026/09/22 08:50:57 OK 1_commit_pending_closure.sql (2.12ms)17482026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.35ms)17492026/09/22 08:50:57 goose: up to current file version: 21750--- PASS: TestGCBugBareHashReferences (0.86s)1751=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17522026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/17532026/09/22 08:50:57 INFO Received create pin request method=POST path=/api/pins/myapp17542026/09/22 08:50:57 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3933145204/001/store/3sfjfyzwvg3gbvacn6pb6bsys3ig6v1z-pinned-file.txt narinfo_key=3sfjfyzwvg3gbvacn6pb6bsys3ig6v1z.narinfo17552026/09/22 08:50:57 INFO Starting cleanup of old closures method=DELETE path=/api/closures17562026/09/22 08:50:57 INFO Garbage collection started17572026/09/22 08:50:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1758=== NAME TestClientWithDependencies1759 client_integration_test.go:614: Built derivation: /build/TestClientWithDependencies1819781963/001/store/rrjhm54chy3yw2r1l85zfq8lp2hkhk8j-test-script17602026/09/22 08:50:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17612026/09/22 08:50:57 INFO Aborted multipart uploads count=017622026/09/22 08:50:57 WARN Force mode enabled - objects will be deleted immediately without grace period1763=== NAME TestClientMultipleUploads1764 client_integration_test.go:359: Created store path 0: /build/TestClientMultipleUploads1311056813/001/store/cp27qm2b9xqnvwz6x3hzp47lfil33ify-test-file-0.txt1765=== CONT TestIsValidCachePath/narinfo1766=== CONT TestIsValidCachePath/short_hash1767=== CONT TestIsValidCachePath/wrong_extension1768=== CONT TestIsValidCachePath/leading_slash1769=== CONT TestIsValidCachePath/empty1770=== CONT TestIsValidCachePath/random_path1771=== CONT TestIsValidCachePath/invalid_char_u1772=== CONT TestIsValidCachePath/invalid_char_e1773=== CONT TestIsValidCachePath/traversal_in_middle1774=== CONT TestIsValidCachePath/traversal_parent1775=== CONT TestIsValidCachePath/index.html1776=== CONT TestIsValidCachePath/nix-cache-info1777=== CONT TestIsValidCachePath/realisation1778=== CONT TestIsValidCachePath/log1779=== CONT TestIsValidCachePath/ls1780=== CONT TestIsValidCachePath/nar_uncompressed1781=== CONT TestIsValidCachePath/nar_bz21782=== CONT TestIsValidCachePath/nar_xz1783=== CONT TestIsValidCachePath/nar_zst1784=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1785--- PASS: TestIsValidCachePath (0.00s)1786 --- PASS: TestIsValidCachePath/narinfo (0.00s)1787 --- PASS: TestIsValidCachePath/short_hash (0.00s)1788 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1789 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1790 --- PASS: TestIsValidCachePath/empty (0.00s)1791 --- PASS: TestIsValidCachePath/random_path (0.00s)1792 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1793 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1794 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1795 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1796 --- PASS: TestIsValidCachePath/index.html (0.00s)1797 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1798 --- PASS: TestIsValidCachePath/realisation (0.00s)1799 --- PASS: TestIsValidCachePath/log (0.00s)1800 --- PASS: TestIsValidCachePath/ls (0.00s)1801 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1802 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1803 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1804 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1805 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1806=== CONT TestParseSingleRange/start_past_EOF1807=== CONT TestParseSingleRange/none1808=== CONT TestParseSingleRange/single_byte1809=== CONT TestParseSingleRange/suffix_exceeds_size1810=== CONT TestParseSingleRange/suffix1811=== CONT TestParseSingleRange/end_clamped_to_size1812=== CONT TestParseSingleRange/open-ended1813=== CONT TestParseSingleRange/closed1814=== CONT TestParseSingleRange/malformed_end_before_start1815=== CONT TestParseSingleRange/malformed_both_empty1816=== CONT TestParseSingleRange/malformed_no_dash1817=== CONT TestParseSingleRange/multi-range_ignored1818=== CONT TestParseSingleRange/unknown_unit1819=== CONT TestParseSingleRange/start_far_past_EOF1820--- PASS: TestParseSingleRange (0.00s)1821 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1822 --- PASS: TestParseSingleRange/none (0.00s)1823 --- PASS: TestParseSingleRange/single_byte (0.00s)1824 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1825 --- PASS: TestParseSingleRange/suffix (0.00s)1826 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1827 --- PASS: TestParseSingleRange/open-ended (0.00s)1828 --- PASS: TestParseSingleRange/closed (0.00s)1829 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1830 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1831 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1832 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1833 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1834 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1835=== CONT TestResolveDBConnectionString/flag_wins1836=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1837=== CONT TestResolveDBConnectionString/missing_file_is_an_error1838=== CONT TestResolveDBConnectionString/file_when_flag_empty1839=== CONT TestResolveDBConnectionString/nothing_configured1840=== CONT TestProxyWriteTimeout/narinfo1841=== CONT TestProxyWriteTimeout/10_GiB_nar1842=== CONT TestProxyWriteTimeout/1_GiB_nar1843=== CONT TestProxyWriteTimeout/unknown_size1844--- PASS: TestProxyWriteTimeout (0.00s)1845 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1846 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1847 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1848 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1849=== CONT TestClientErrorHandling/InvalidStorePath1850--- PASS: TestResolveDBConnectionString (0.00s)1851 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1852 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1853 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1854 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1855 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1856=== NAME TestClientWithDependencies1857 client_integration_test.go:616: Found 1 dependencies (including self)18582026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures1859=== CONT TestClientErrorHandling/ServerNotAvailable1860=== NAME TestClientMultipleUploads1861 client_integration_test.go:359: Created store path 1: /build/TestClientMultipleUploads1311056813/001/store/r2nygypv2nbvwwjwj339yppj9fqkz9p7-test-file-1.txt1862=== NAME TestClientIntegration1863 client_integration_test.go:287: Created store path: /build/TestClientIntegration1027771320/002/store/12wf267jp273zr8wkvxbix0sa42mhk5l-test-file.txt1864--- PASS: TestObjectStatsTrigger (0.63s)1865=== CONT TestClientErrorHandling/InvalidAuthToken1866=== NAME TestClientMultipleUploads1867 client_integration_test.go:359: Created store path 2: /build/TestClientMultipleUploads1311056813/001/store/9g42hkm2bmpbqsd5xz2ncrkyvnadppp2-test-file-2.txt18682026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures18692026-09-22 08:50:57.895 UTC [1067] ERROR: relation "goose_db_version" does not exist at character 3618702026-09-22 08:50:57.895 UTC [1067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18712026/09/22 08:50:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18722026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures18732026/09/22 08:50:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18742026/09/22 08:50:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18752026/09/22 08:50:57 INFO Uploading rrjhm54chy3yw2r1l85zfq8lp2hkhk8j-test-script (136B)18762026/09/22 08:50:57 OK 20241026095416_initial_model.sql (12.51ms)18772026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)18782026/09/22 08:50:57 WARN Failed to register uploaded object key=log/i0in7npssz51bkzpl4knzcj85g4fmagf-test-script.drv error="server returned 404: 404 page not found\n"18792026/09/22 08:50:57 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18802026/09/22 08:50:57 OK 20251218171726_add_pins.sql (4.26ms)18812026/09/22 08:50:57 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18822026/09/22 08:50:57 WARN Failed to register uploaded object key=rrjhm54chy3yw2r1l85zfq8lp2hkhk8j.ls error="server returned 404: 404 page not found\n"18832026/09/22 08:50:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18842026/09/22 08:50:57 INFO Signed narinfos id=1 count=118852026/09/22 08:50:57 INFO Uploading 1 narinfos18862026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)18872026/09/22 08:50:57 OK 20260905000000_add_claims.sql (4.22ms)18882026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18892026/09/22 08:50:57 WARN Failed to register uploaded object key=rrjhm54chy3yw2r1l85zfq8lp2hkhk8j.narinfo error="server returned 404: 404 page not found\n"18902026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (3.69ms)18912026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000018922026/09/22 08:50:57 OK 1_commit_pending_closure.sql (2.85ms)18932026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures18942026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.75ms)18952026/09/22 08:50:57 goose: up to current file version: 218962026/09/22 08:50:57 INFO Completed upload id=118972026/09/22 08:50:57 INFO Upload complete. (77ms)18982026/09/22 08:50:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18992026/09/22 08:50:57 INFO Uploading mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf-shared-dep (136B)1900=== NAME TestClientWithDependencies1901 client_integration_test.go:618: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1819781963/001/store) requires matching store prefix19022026/09/22 08:50:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"19032026/09/22 08:50:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1904--- PASS: TestService_NativeMTLS (0.60s)1905=== CONT TestServerTLSConfig/no_client_CA1906=== CONT TestServerTLSConfig/not_a_PEM_file19072026/09/22 08:50:57 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1908=== CONT TestServerTLSConfig/missing_CA_file1909--- PASS: TestServerTLSConfig (0.00s)1910 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1911 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1912 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1913=== CONT TestCacheConfigHandler/full_config,_no_issuer1914=== CONT TestCacheConfigHandler/no_signing_keys1915=== CONT TestCacheConfigHandler/no_cache_url_configured1916=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1917--- PASS: TestCacheConfigHandler (0.00s)1918 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1919 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1920 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1921 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1922--- PASS: TestClientWithDependencies (0.90s)19232026-09-22 08:50:57.952 UTC [1174] ERROR: relation "goose_db_version" does not exist at character 3619242026-09-22 08:50:57.952 UTC [1174] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19252026/09/22 08:50:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19262026/09/22 08:50:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19272026/09/22 08:50:57 WARN Failed to register uploaded object key=mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf.ls error="server returned 404: 404 page not found\n"19282026/09/22 08:50:57 INFO Signed narinfos id=2 count=119292026/09/22 08:50:57 INFO Uploading 1 narinfos19302026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19312026/09/22 08:50:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19322026/09/22 08:50:57 WARN Failed to register uploaded object key=mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf.narinfo error="server returned 404: 404 page not found\n"19332026/09/22 08:50:57 OK 20241026095416_initial_model.sql (9.1ms)19342026/09/22 08:50:57 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)19352026/09/22 08:50:57 INFO Completed upload id=219362026/09/22 08:50:57 INFO Upload complete. (96ms)19372026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures19382026/09/22 08:50:57 OK 20251218171726_add_pins.sql (3.76ms)19392026/09/22 08:50:57 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19402026/09/22 08:50:57 INFO Uploading fsiyyh17rdd3mckcb5psz99p75z6vnhs-top (224B)19412026/09/22 08:50:57 INFO Uploading mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf-shared-dep (136B)1942--- PASS: TestService_ReadScope_PublicByDefault (0.56s)19432026/09/22 08:50:57 OK 20260628120000_add_object_size_and_stats.sql (3.58ms)19442026/09/22 08:50:57 OK 20260905000000_add_claims.sql (3.32ms)19452026/09/22 08:50:57 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19462026/09/22 08:50:57 WARN Failed to register uploaded object key=nar/05wlgc0fx5b4xaj37vzccmzask4jg5kkmzh8fg4nawvfvsagdicg.nar.zst error="server returned 404: 404 page not found\n"19472026/09/22 08:50:57 OK 20260920000000_drop_claims.sql (2.34ms)19482026/09/22 08:50:57 goose: successfully migrated database to version: 2026092000000019492026/09/22 08:50:57 OK 1_commit_pending_closure.sql (1.76ms)19502026/09/22 08:50:57 OK 2_object_stats_trigger.sql (1.34ms)19512026/09/22 08:50:57 goose: up to current file version: 219522026/09/22 08:50:57 WARN Failed to register uploaded object key=mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf.ls error="server returned 404: 404 page not found\n"19532026/09/22 08:50:57 WARN Failed to register uploaded object key=fsiyyh17rdd3mckcb5psz99p75z6vnhs.ls error="server returned 404: 404 page not found\n"19542026/09/22 08:50:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19552026/09/22 08:50:57 INFO Signed narinfos id=1 count=119562026/09/22 08:50:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign19572026/09/22 08:50:57 INFO Signed narinfos id=3 count=119582026/09/22 08:50:57 INFO Uploading 2 narinfos19592026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures19602026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19612026/09/22 08:50:57 WARN Failed to register uploaded object key=mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf.narinfo error="server returned 404: 404 page not found\n"19622026/09/22 08:50:57 WARN Failed to register uploaded object key=fsiyyh17rdd3mckcb5psz99p75z6vnhs.narinfo error="server returned 404: 404 page not found\n"19632026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures19642026/09/22 08:50:57 INFO Completed upload id=119652026/09/22 08:50:57 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete19662026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures19672026/09/22 08:50:57 INFO Received uploads request method=POST path=/api/pending_closures19682026/09/22 08:50:58 INFO Completed upload id=319692026/09/22 08:50:58 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19702026/09/22 08:50:58 INFO Upload complete. (241ms)19712026/09/22 08:50:58 INFO Uploading 9g42hkm2bmpbqsd5xz2ncrkyvnadppp2-test-file-2.txt (160B)19722026/09/22 08:50:58 INFO Uploading cp27qm2b9xqnvwz6x3hzp47lfil33ify-test-file-0.txt (160B)19732026/09/22 08:50:58 INFO Uploading r2nygypv2nbvwwjwj339yppj9fqkz9p7-test-file-1.txt (160B)19742026/09/22 08:50:58 WARN readiness check failed error="closed pool"1975--- PASS: TestService_readinessHandler (0.56s)1976=== NAME TestClientSharedPathCommittedMidPush1977 client_integration_test.go:681: Retrieved narinfo from S3:1978 StorePath: /build/TestClientSharedPathCommittedMidPush2386713652/001/store/mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf-shared-dep1979 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1980 Compression: zstd1981 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821982 NarSize: 1361983 References: 1984 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19852026/09/22 08:50:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19862026/09/22 08:50:58 INFO Uploading 12wf267jp273zr8wkvxbix0sa42mhk5l-test-file.txt (152B)19872026/09/22 08:50:58 INFO Received cleanup request method=DELETE path=/api/pending_closures19882026/09/22 08:50:58 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1989 client_integration_test.go:681: Retrieved narinfo from S3:1990 StorePath: /build/TestClientSharedPathCommittedMidPush2386713652/001/store/fsiyyh17rdd3mckcb5psz99p75z6vnhs-top1991 URL: nar/05wlgc0fx5b4xaj37vzccmzask4jg5kkmzh8fg4nawvfvsagdicg.nar.zst1992 Compression: zstd1993 NarHash: sha256:05wlgc0fx5b4xaj37vzccmzask4jg5kkmzh8fg4nawvfvsagdicg1994 NarSize: 2241995 References: /build/TestClientSharedPathCommittedMidPush2386713652/001/store/mvfg5m1lxwwl9mgsdgwswpd3gj5chlrf-shared-dep1996 CA: text:sha256:0v9l6n29j9f6n3zdya1ldga97spg2dnihagji5087b90486v1y4q19972026/09/22 08:50:58 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19982026/09/22 08:50:58 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1999=== NAME TestClientCADerivations2000 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1792173706/001/store/n6pwsqg301xflf5a2mxy9pc21kqzzi9j-ca-test20012026/09/22 08:50:58 INFO Aborted multipart uploads count=120022026/09/22 08:50:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20032026/09/22 08:50:58 WARN Failed to register uploaded object key=9g42hkm2bmpbqsd5xz2ncrkyvnadppp2.ls error="server returned 404: 404 page not found\n"20042026/09/22 08:50:58 WARN Failed to register uploaded object key=r2nygypv2nbvwwjwj339yppj9fqkz9p7.ls error="server returned 404: 404 page not found\n"20052026/09/22 08:50:58 WARN Failed to register uploaded object key=cp27qm2b9xqnvwz6x3hzp47lfil33ify.ls error="server returned 404: 404 page not found\n"20062026/09/22 08:50:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20072026/09/22 08:50:58 INFO Signed narinfos id=3 count=120082026/09/22 08:50:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20092026/09/22 08:50:58 INFO Signed narinfos id=1 count=12010--- PASS: TestClientSharedPathCommittedMidPush (1.00s)20112026/09/22 08:50:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20122026/09/22 08:50:58 INFO Signed narinfos id=2 count=120132026/09/22 08:50:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20142026/09/22 08:50:58 INFO Uploading 3 narinfos20152026/09/22 08:50:58 WARN Failed to register uploaded object key=12wf267jp273zr8wkvxbix0sa42mhk5l.ls error="server returned 404: 404 page not found\n"20162026/09/22 08:50:58 INFO Signed narinfos id=1 count=12017--- PASS: TestMultipartCleanup (0.74s)20182026/09/22 08:50:58 INFO Uploading 1 narinfos20192026/09/22 08:50:58 WARN Failed to register uploaded object key=cp27qm2b9xqnvwz6x3hzp47lfil33ify.narinfo error="server returned 404: 404 page not found\n"20202026/09/22 08:50:58 WARN Failed to register uploaded object key=9g42hkm2bmpbqsd5xz2ncrkyvnadppp2.narinfo error="server returned 404: 404 page not found\n"20212026/09/22 08:50:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20222026/09/22 08:50:58 WARN Failed to register uploaded object key=r2nygypv2nbvwwjwj339yppj9fqkz9p7.narinfo error="server returned 404: 404 page not found\n"20232026/09/22 08:50:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20242026/09/22 08:50:58 WARN Failed to register uploaded object key=12wf267jp273zr8wkvxbix0sa42mhk5l.narinfo error="server returned 404: 404 page not found\n"20252026/09/22 08:50:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.914493ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20262026/09/22 08:50:58 INFO Completed upload id=120272026/09/22 08:50:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20282026/09/22 08:50:58 INFO Completed upload id=120292026/09/22 08:50:58 INFO Upload complete. (108ms)20302026/09/22 08:50:58 INFO Completed upload id=220312026/09/22 08:50:58 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20322026/09/22 08:50:58 INFO Completed upload id=320332026/09/22 08:50:58 INFO Upload complete. (118ms)2034=== NAME TestClientMultipleUploads2035 client_integration_test.go:370: Uploaded 3 paths in 147.168782ms2036--- PASS: TestClientMultipleUploads (0.89s)2037=== NAME TestClientCADerivations2038 client_ca_test.go:139: Found 1 dependencies (including self)20392026/09/22 08:50:58 INFO All 1 paths already cached2040=== NAME TestClientIntegration2041 client_integration_test.go:313: Retrieved narinfo from S3:2042 StorePath: /build/TestClientIntegration1027771320/002/store/12wf267jp273zr8wkvxbix0sa42mhk5l-test-file.txt2043 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2044 Compression: zstd2045 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12046 NarSize: 1522047 References: 2048 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12049 client_integration_test.go:314: Retrieved .ls file from S3 (compressed size: 77 bytes)2050 client_integration_test.go:314: Decompressed .ls content (64 bytes):2051 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2052 client_integration_test.go:317: Testing garbage collection...2053=== NAME TestNARDeduplicationMetadataUploadBug2054 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1849002427/001/store/3hscvj9f2a7lq71lwj7libwg9q39535b-file1.txt2055=== RUN TestService_RequireScope_OIDC/builder_may_write2056=== PAUSE TestService_RequireScope_OIDC/builder_may_write2057=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2058=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2059=== RUN TestService_RequireScope_OIDC/ops_may_admin2060=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2061=== RUN TestService_RequireScope_OIDC/ops_may_not_write2062=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2063=== RUN TestService_RequireScope_OIDC/reader_may_not_write2064=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2065=== RUN TestService_RequireScope_OIDC/static_token_may_admin2066=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2067=== RUN TestService_RequireScope_OIDC/static_token_may_write2068=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2069=== RUN TestService_RequireScope_OIDC/reader_may_read2070=== PAUSE TestService_RequireScope_OIDC/reader_may_read2071=== RUN TestService_RequireScope_OIDC/writer_implies_read2072=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2073=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2074=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2075=== CONT TestService_RequireScope_OIDC/builder_may_write2076=== CONT TestService_RequireScope_OIDC/static_token_may_admin2077=== CONT TestService_RequireScope_OIDC/ops_may_not_write2078=== CONT TestService_RequireScope_OIDC/reader_may_not_write2079=== CONT TestService_RequireScope_OIDC/writer_implies_read2080=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2081=== CONT TestService_RequireScope_OIDC/ops_may_admin2082=== CONT TestService_RequireScope_OIDC/reader_may_read2083=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2084=== CONT TestService_RequireScope_OIDC/static_token_may_write2085--- PASS: TestService_RequireScope_OIDC (0.69s)2086 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2087 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2088 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2089 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2090 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2091 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2092 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2093 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2094 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2095 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2096=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2097=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2098=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2099=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2100=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2101=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2102=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2103=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2104=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2105=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2106=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured21072026/09/22 08:50:58 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]2108=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21092026/09/22 08:50:58 WARN Authentication failed token_preview=eyJhbGciOi...FZ_q-_XUjA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2110--- PASS: TestService_AuthMiddleware_OIDC (0.77s)2111 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2112 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2113 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2114 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)21152026/09/22 08:50:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures21162026/09/22 08:50:58 INFO Garbage collection started21172026/09/22 08:50:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21182026/09/22 08:50:58 WARN mTLS auth: bound subjects configured but subject DN unavailable21192026/09/22 08:50:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2120--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.52s)21212026/09/22 08:50:58 INFO Aborted multipart uploads count=021222026/09/22 08:50:58 WARN Force mode enabled - objects will be deleted immediately without grace period2123=== NAME TestOrphanedObjectsGC2124 orphaned_objects_gc_test.go:290: GC Test Summary:2125 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2126 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2127 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2128 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2129 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2130--- PASS: TestOrphanedObjectsGC (0.96s)2131--- PASS: TestService_healthCheckHandler (0.55s)21322026/09/22 08:50:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2133--- PASS: TestService_ReadAuthMiddleware (0.54s)21342026/09/22 08:50:58 INFO Received uploads request method=POST path=/api/pending_closures21352026/09/22 08:50:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21362026/09/22 08:50:58 INFO Uploading n6pwsqg301xflf5a2mxy9pc21kqzzi9j-ca-test (144B)21372026/09/22 08:50:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21382026/09/22 08:50:58 WARN Failed to register uploaded object key=log/wsmr3zpij3fms126srqs3ar2rhx6a1jp-ca-test.drv error="server returned 404: 404 page not found\n"21392026/09/22 08:50:58 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21402026/09/22 08:50:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign2141--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.57s)21422026/09/22 08:50:58 INFO Signed narinfos id=1 count=121432026/09/22 08:50:58 WARN Failed to register uploaded object key=n6pwsqg301xflf5a2mxy9pc21kqzzi9j.ls error="server returned 404: 404 page not found\n"21442026/09/22 08:50:58 INFO Uploading 1 narinfos21452026/09/22 08:50:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21462026/09/22 08:50:58 WARN Failed to register uploaded object key=n6pwsqg301xflf5a2mxy9pc21kqzzi9j.narinfo error="server returned 404: 404 page not found\n"21472026/09/22 08:50:58 INFO Completed upload id=121482026/09/22 08:50:58 INFO Upload complete. (97ms)2149=== NAME TestClientCADerivations2150 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1792173706/001/store/n6pwsqg301xflf5a2mxy9pc21kqzzi9j-ca-test2151 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2152 Compression: zstd2153 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2154 NarSize: 1442155 References: 2156 Deriver: /build/TestClientCADerivations1792173706/001/store/wsmr3zpij3fms126srqs3ar2rhx6a1jp-ca-test.drv2157 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2158 client_ca_test.go:185: Checking for realisation files in S3...2159 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2160 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21612026/09/22 08:50:58 INFO Received uploads request method=POST path=/api/pending_closures21622026/09/22 08:50:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21632026/09/22 08:50:58 INFO Uploading 3hscvj9f2a7lq71lwj7libwg9q39535b-file1.txt (160B)21642026/09/22 08:50:58 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"21652026/09/22 08:50:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21662026/09/22 08:50:58 WARN Failed to register uploaded object key=3hscvj9f2a7lq71lwj7libwg9q39535b.ls error="server returned 404: 404 page not found\n"21672026/09/22 08:50:58 INFO Signed narinfos id=1 count=121682026/09/22 08:50:58 INFO Uploading 1 narinfos21692026/09/22 08:50:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.115406ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21702026/09/22 08:50:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21712026/09/22 08:50:58 WARN Failed to register uploaded object key=3hscvj9f2a7lq71lwj7libwg9q39535b.narinfo error="server returned 404: 404 page not found\n"21722026/09/22 08:50:58 INFO Completed upload id=121732026/09/22 08:50:58 INFO Upload complete. (122ms)2174=== NAME TestNARDeduplicationMetadataUploadBug2175 metadata_upload_test.go:54: Retrieved narinfo from S3:2176 StorePath: /build/TestNARDeduplicationMetadataUploadBug1849002427/001/store/3hscvj9f2a7lq71lwj7libwg9q39535b-file1.txt2177 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2178 Compression: zstd2179 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2180 NarSize: 1602181 References: 2182 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2183 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2184 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2185 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2186 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1849002427/001/store/qj8rjprvhx5s0746i3xwp8qff81kgdgz-file2.txt21872026/09/22 08:50:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2188=== NAME TestClientCADerivations2189 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2190 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2191 error: binary cache 's3://bucket46?endpoint=http://localhost:33459®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1792173706/001/store'2192 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12193--- PASS: TestClientCADerivations (1.06s)21942026/09/22 08:50:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21952026/09/22 08:50:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21962026/09/22 08:50:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21972026/09/22 08:50:58 INFO Received uploads request method=POST path=/api/pending_closures21982026/09/22 08:50:58 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21992026/09/22 08:50:58 WARN Failed to register uploaded object key=qj8rjprvhx5s0746i3xwp8qff81kgdgz.ls error="server returned 404: 404 page not found\n"22002026/09/22 08:50:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22012026/09/22 08:50:58 INFO Signed narinfos id=2 count=122022026/09/22 08:50:58 INFO Uploading 1 narinfos22032026/09/22 08:50:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22042026/09/22 08:50:58 WARN Failed to register uploaded object key=qj8rjprvhx5s0746i3xwp8qff81kgdgz.narinfo error="server returned 404: 404 page not found\n"22052026/09/22 08:50:58 INFO Completed upload id=222062026/09/22 08:50:58 INFO Upload complete. (85ms)2207=== NAME TestNARDeduplicationMetadataUploadBug2208 metadata_upload_test.go:76: Retrieved narinfo from S3:2209 StorePath: /build/TestNARDeduplicationMetadataUploadBug1849002427/001/store/qj8rjprvhx5s0746i3xwp8qff81kgdgz-file2.txt2210 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2211 Compression: zstd2212 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2213 NarSize: 1602214 References: 2215 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2216 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2217 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2218 {"version":1,"root":{"type":"regular","size":44}}2219--- PASS: TestNARDeduplicationMetadataUploadBug (0.91s)22202026/09/22 08:50:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.023671ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2221=== NAME TestOrphanedObjectsGCStressTest2222 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2223 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2224--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2225 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2226 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)2227 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.41s)2228=== NAME TestOrphanedObjectsGCStressTest2229 orphaned_objects_gc_test.go:509: Stress test completed successfully:2230 orphaned_objects_gc_test.go:510: - Active objects preserved: 202231 orphaned_objects_gc_test.go:511: - Objects deleted: 2102232 orphaned_objects_gc_test.go:512: - Total GC'd: 2102233--- PASS: TestOrphanedObjectsGCStressTest (2.92s)22342026/09/22 08:50:59 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=022352026/09/22 08:50:59 INFO Vacuumed table table=pending_closures22362026/09/22 08:50:59 INFO Vacuumed table table=pending_objects22372026/09/22 08:50:59 INFO Vacuumed table table=multipart_uploads22382026/09/22 08:50:59 INFO Vacuumed table table=closures22392026/09/22 08:50:59 INFO Vacuumed table table=objects22402026/09/22 08:50:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.591044259s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22412026/09/22 08:50:59 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=022422026/09/22 08:50:59 INFO Vacuumed table table=pending_closures22432026/09/22 08:50:59 INFO Vacuumed table table=pending_objects22442026/09/22 08:50:59 INFO Vacuumed table table=multipart_uploads22452026/09/22 08:50:59 INFO Vacuumed table table=closures22462026/09/22 08:50:59 INFO Vacuumed table table=objects22472026/09/22 08:50:59 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02248=== NAME TestPinProtectsFromGC2249 client_integration_test.go:795: Pin successfully protected closure from garbage collection2250--- PASS: TestPinProtectsFromGC (3.12s)22512026/09/22 08:51:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02252=== NAME TestClientIntegration2253 client_integration_test.go:324: Objects in database after GC:2254 client_integration_test.go:324: Successfully deleted all objects with GC --force2255--- PASS: TestClientIntegration (2.91s)22562026/09/22 08:51:00 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22572026/09/22 08:51:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.365282ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22582026/09/22 08:51:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.680088ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/09/22 08:51:01 WARN Rate limiter enabled after throttle name=s3-test rate=522602026/09/22 08:51:01 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2261=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2262 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102263 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002264--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.30s)22652026/09/22 08:51:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.768318ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22662026/09/22 08:51:02 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.691750808s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22672026/09/22 08:51:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22682026/09/22 08:51:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22692026/09/22 08:51:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.37134ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22702026/09/22 08:51:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.069171ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22712026/09/22 08:51:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=735.702545ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22722026/09/22 08:51:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.684187356s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2273--- PASS: TestClientErrorHandling (0.00s)2274 --- PASS: TestClientErrorHandling/InvalidStorePath (0.42s)2275 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.51s)2276 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.57s)2277FAIL22782026-09-22 08:51:07.788 UTC [129] LOG: received smart shutdown request22792026-09-22 08:51:07.794 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122802026-09-22 08:51:07.809 UTC [134] LOG: shutting down22812026-09-22 08:51:07.809 UTC [134] LOG: checkpoint starting: shutdown immediate22822026-09-22 08:51:08.956 UTC [134] LOG: checkpoint complete: wrote 10864 buffers (66.3%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.219 s, sync=0.897 s, total=1.148 s; sync files=19406, longest=0.002 s, average=0.001 s; distance=264839 kB, estimate=264839 kB; lsn=0/11A07960, redo lsn=0/11A0796022832026-09-22 08:51:09.065 UTC [129] LOG: database system is shut down