niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #339
· raw
1tribuchet: building on jamie2Running 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 TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestShellSplit97=== CONT TestEncodeNixBase32WithRealHash98=== CONT TestDoWithRetry_BodyReplayedViaGetBody99=== CONT TestResolveStorePath100=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess101=== CONT TestRateLimiterFeedback102=== RUN TestRateLimiterFeedback/429_enables_limiter1032026/10/01 10:24:09 WARN Rate limiter enabled after throttle name=server-test rate=5104=== PAUSE TestRateLimiterFeedback/429_enables_limiter105=== RUN TestRateLimiterFeedback/503_enables_limiter106=== PAUSE TestRateLimiterFeedback/503_enables_limiter107=== CONT TestPathInfoCACompatibility108=== CONT TestGetStorePathHash109=== CONT TestConvertHashToNix32110=== CONT TestUploadMultipart_SupersededByPeer111=== CONT TestEncodeNixBase32112=== CONT TestDumpPathWriterError113=== CONT TestDumpPathSingleFile114=== CONT TestDumpPathMatchesNix115=== CONT TestSetClientTLSErrors116=== CONT TestScriptTokenEmptyCommand117=== CONT TestScriptTokenScriptFails118=== CONT TestScriptTokenBadJSON119=== CONT TestPathInfoHashCompatibility120=== CONT TestScriptTokenEmptyToken121=== CONT TestParsePathInfoJSONMultiplePaths122=== CONT TestScriptTokenCachesUntilRefresh123=== CONT TestParsePathInfoJSON124--- PASS: TestEncodeNixBase32WithRealHash (0.00s)125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestFileTokenEmpty127=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter128=== RUN TestPathInfoCACompatibility/null_ca_field129--- PASS: TestShellSplit (0.00s)130=== RUN TestGetStorePathHash/valid_store_path131=== RUN TestConvertHashToNix32/SRI_format_to_Nix32132=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32133=== RUN TestConvertHashToNix32/already_Nix32_format134=== RUN TestUploadMultipart_SupersededByPeer/exists135=== PAUSE TestConvertHashToNix32/already_Nix32_format136--- PASS: TestResolveStorePath (0.00s)137=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter138=== CONT TestFileTokenMissing139=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter140=== RUN TestEncodeNixBase32/test_string_hash141=== RUN TestConvertHashToNix32/invalid_format142=== PAUSE TestPathInfoCACompatibility/null_ca_field143=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths144=== PAUSE TestEncodeNixBase32/test_string_hash145=== PAUSE TestGetStorePathHash/valid_store_path146=== RUN TestParsePathInfoJSON/Nix_format147=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== PAUSE TestUploadMultipart_SupersededByPeer/exists150--- PASS: TestScriptTokenEmptyCommand (0.00s)151=== CONT TestFileTokenReadsAndCaches1522026/10/01 10:24:09 WARN Rate limiter enabled after throttle name=server-test rate=5153=== RUN TestEncodeNixBase32/empty_input154=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter155=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon156=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon157=== PAUSE TestConvertHashToNix32/invalid_format158=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths159=== RUN TestPathInfoCACompatibility/old_string_format_-_text160=== CONT TestStaticToken161=== RUN TestGetStorePathHash/basename_without_hyphen_should_error162=== PAUSE TestParsePathInfoJSON/Nix_format163=== PAUSE TestEncodeNixBase32/empty_input1642026/10/01 10:24:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:32817165=== CONT TestCaseHackSuffix166=== RUN TestUploadMultipart_SupersededByPeer/missing167--- PASS: TestFileTokenEmpty (0.00s)168--- PASS: TestDoServerRequestAttachesToken (0.01s)169=== CONT TestPartSizeForNAR170=== RUN TestPartSizeForNAR/zero_stays_at_minimum171=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum172=== RUN TestPartSizeForNAR/small_stays_at_minimum173=== PAUSE TestPartSizeForNAR/small_stays_at_minimum174=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum175=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum176=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts177=== CONT TestStreamPushRequestLine178=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI179--- PASS: TestFileTokenMissing (0.00s)180=== CONT TestClientSignaturesByStorePath181=== CONT TestSetClientTLS182--- PASS: TestClientSignaturesByStorePath (0.00s)183=== CONT TestSetClientTLSDoesNotMutateDefaultTransport184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text185=== RUN TestParsePathInfoJSON/Lix_format186=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error187=== PAUSE TestUploadMultipart_SupersededByPeer/missing188--- PASS: TestScriptTokenScriptFails (0.01s)189--- PASS: TestStaticToken (0.00s)190=== CONT TestStreamPushReportsSignatures191=== RUN TestSetClientTLSErrors/missing_cert_file192=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI193=== CONT TestUploadMultipart_PartsInParallel1942026/10/01 10:24:09 WARN Rate limiter backed off name=server-test rate=51952026/10/01 10:24:09 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:328171962026/10/01 10:24:09 ERROR Upload failed error=boom count=1197=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive198=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts199=== RUN TestPartSizeForNAR/1_TiB200=== CONT TestRegisterUploadedObjectReusesConnections201=== CONT TestStreamPushBatchesUnderLoad2022026/10/01 10:24:09 ERROR Upload failed error=boom count=1203=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths204=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths205=== CONT TestFilterOversizedClosures206=== RUN TestFilterOversizedClosures/no_limit_keeps_everything207=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything208=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped209=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== RUN TestFilterOversizedClosures/all_closures_skipped211=== PAUSE TestFilterOversizedClosures/all_closures_skipped212=== CONT TestRateLimiterFeedback/429_enables_limiter213=== PAUSE TestParsePathInfoJSON/Lix_format214=== RUN TestParsePathInfoJSON/empty_input215=== PAUSE TestParsePathInfoJSON/empty_input216=== RUN TestParsePathInfoJSON/whitespace_only217=== PAUSE TestParsePathInfoJSON/whitespace_only218=== RUN TestSetClientTLS/rejects_connection_without_client_cert219=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter220=== RUN TestParsePathInfoJSON/invalid_JSON221=== PAUSE TestParsePathInfoJSON/invalid_JSON222=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert223=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA224=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA225=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter226=== CONT TestRateLimiterFeedback/503_enables_limiter227--- PASS: TestScriptTokenEmptyToken (0.01s)228--- PASS: TestFileTokenReadsAndCaches (0.00s)229--- PASS: TestScriptTokenBadJSON (0.01s)230--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)231--- PASS: TestStreamPushReportsSignatures (0.00s)232--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)233--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.10s)234=== RUN TestSetClientTLS/preserves_debug_logging_transport235=== PAUSE TestSetClientTLS/preserves_debug_logging_transport236=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error237=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error238=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error239=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error240=== CONT TestStreamPushIsolatesFailures241=== CONT TestConvertHashToNix32/SRI_format_to_Nix32242=== PAUSE TestSetClientTLSErrors/missing_cert_file243=== RUN TestSetClientTLSErrors/missing_key_file244=== PAUSE TestSetClientTLSErrors/missing_key_file245=== RUN TestSetClientTLSErrors/missing_ca_file246=== PAUSE TestSetClientTLSErrors/missing_ca_file247=== RUN TestSetClientTLSErrors/invalid_ca_file248=== PAUSE TestSetClientTLSErrors/invalid_ca_file249=== CONT TestConvertHashToNix32/already_Nix32_format250=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512251=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512252=== CONT TestConvertHashToNix32/invalid_format253--- PASS: TestConvertHashToNix32 (0.01s)254 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)255 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)256 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)257--- PASS: TestCaseHackSuffix (0.09s)2582026/10/01 10:24:09 ERROR Upload failed error="bad path" count=3259--- PASS: TestStreamPushIsolatesFailures (0.00s)260=== CONT TestFilterOversizedClosures/no_limit_keeps_everything261=== CONT TestStreamPushGivesUpOnDeadServer2622026/10/01 10:24:09 WARN Rate limiter enabled after throttle name=server-test rate=52632026/10/01 10:24:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33723264=== CONT TestShellSplitErrors265--- PASS: TestShellSplitErrors (0.00s)266=== CONT TestParsePathInfoJSON/Nix_format2672026/10/01 10:24:09 ERROR Upload failed error="connection refused" count=202682026/10/01 10:24:09 ERROR Server seems unavailable, giving up on batch untried=17269=== CONT TestFilterOversizedClosures/all_closures_skipped2702026/10/01 10:24:09 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50271=== CONT TestSetClientTLS/rejects_connection_without_client_cert2722026/10/01 10:24:09 WARN Rate limiter backed off name=server-test rate=5273=== CONT TestParsePathInfoJSON/invalid_JSON2742026/10/01 10:24:09 WARN Rate limiter enabled after throttle name=server-test rate=5275=== CONT TestParsePathInfoJSON/whitespace_only276=== CONT TestGetStorePathHash/valid_store_path2772026/10/01 10:24:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39213278=== CONT TestSetClientTLS/preserves_debug_logging_transport279=== CONT TestStreamPushReportsEveryPath280=== CONT TestParsePathInfoJSON/empty_input281=== CONT TestGetStorePathHash/basename_without_hyphen_should_error282--- PASS: TestDumpPathSingleFile (0.09s)283--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)2842026/10/01 10:24:09 WARN Rate limiter backed off name=server-test rate=5285=== CONT TestEncodeNixBase32/test_string_hash286=== CONT TestSetClientTLSErrors/missing_cert_file287=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive288=== CONT TestUploadMultipart_SupersededByPeer/exists289=== CONT TestSetClientTLSErrors/invalid_ca_file290=== PAUSE TestPartSizeForNAR/1_TiB291=== CONT TestUploadMultipart_SupersededByPeer/missing292=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA293=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths294=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2952026/10/01 10:24:09 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=2000296=== RUN TestPartSizeForNAR/5_TiB_S3_max_object297=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object298=== RUN TestPartSizeForNAR/capped_at_5_GiB299=== PAUSE TestPartSizeForNAR/capped_at_5_GiB300=== CONT TestSetClientTLSErrors/missing_key_file301=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon302=== CONT TestSetClientTLSErrors/missing_ca_file303=== CONT TestPartSizeForNAR/zero_stays_at_minimum304=== CONT TestPartSizeForNAR/capped_at_5_GiB305=== CONT TestPartSizeForNAR/5_TiB_S3_max_object306=== CONT TestPartSizeForNAR/1_TiB307=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts308=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum309=== CONT TestPartSizeForNAR/small_stays_at_minimum310=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512311=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths312=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error313--- PASS: TestStreamPushReportsEveryPath (0.00s)314=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error315=== CONT TestEncodeNixBase32/empty_input316=== RUN TestPathInfoCACompatibility/new_structured_format_-_text317=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text318=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method319=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)320=== CONT TestParsePathInfoJSON/Lix_format321=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI322--- PASS: TestRateLimiterFeedback (0.01s)323 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.08s)326 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)327=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method328=== CONT TestPathInfoCACompatibility/null_ca_field329=== CONT TestPathInfoCACompatibility/new_structured_format_-_text330=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive331--- PASS: TestPartSizeForNAR (0.10s)332 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)333 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)334 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)335 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)336 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)337 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)338 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)339=== CONT TestPathInfoCACompatibility/old_string_format_-_text340=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method341--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)342 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)343 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)344--- PASS: TestScriptTokenCachesUntilRefresh (0.11s)345--- PASS: TestFilterOversizedClosures (0.00s)346 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)347 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)348 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)349--- PASS: TestGetStorePathHash (0.10s)350 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)351 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)352 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)353 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)354--- PASS: TestEncodeNixBase32 (0.00s)355 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)356 --- PASS: TestEncodeNixBase32/empty_input (0.00s)357--- PASS: TestParsePathInfoJSON (0.09s)358 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)359 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)360 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)361 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)362 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)363--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)364 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)365 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)366--- PASS: TestPathInfoHashCompatibility (0.09s)367 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)368 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)369 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)370 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)371--- PASS: TestPathInfoCACompatibility (0.11s)372 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)373 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)374 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)375 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)376 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)377--- PASS: TestSetClientTLSErrors (0.09s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.01s)380 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)381 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3822026/10/01 10:24:09 http: TLS handshake error from 127.0.0.1:57586: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.09s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestStreamPushRequestLine (0.12s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.12s)389--- PASS: TestDumpPathWriterError (0.13s)390--- PASS: TestStreamPushBatchesUnderLoad (0.13s)391--- PASS: TestDumpPathMatchesNix (0.17s)392--- PASS: TestUploadMultipart_PartsInParallel (0.71s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres440314376/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres440314376/data -l logfile start422423/build/postgres440314376:5432 - no response4242026-10-01 10:24:11.788 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:24:11.788 UTC [128] LOG: listening on Unix socket "/build/postgres440314376/.s.PGSQL.5432"4262026-10-01 10:24:11.793 UTC [135] LOG: database system was shut down at 2026-10-01 10:24:11 UTC4272026-10-01 10:24:11.797 UTC [128] LOG: database system is ready to accept connections428/build/postgres440314376:5432 - accepting connections429{"timestamp":"2026-10-01T10:24:12.095378476Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"650f5867-f104-4fc4-8f2a-242c66c5ffbe","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(398)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026-10-01 10:24:12.303 UTC [563] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 10:24:12.303 UTC [563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 10:24:12 OK 20241026095416_initial_model.sql (7.45ms)4762026/10/01 10:24:12 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)4772026/10/01 10:24:12 OK 20251218171726_add_pins.sql (2.38ms)4782026/10/01 10:24:12 OK 20260628120000_add_object_size_and_stats.sql (1.9ms)4792026/10/01 10:24:12 OK 20260905000000_add_claims.sql (2.33ms)4802026/10/01 10:24:12 OK 20260920000000_drop_claims.sql (1.36ms)4812026/10/01 10:24:12 OK 20260923120000_add_pushes.sql (935.03µs)4822026/10/01 10:24:12 goose: successfully migrated database to version: 202609231200004832026/10/01 10:24:12 OK 1_commit_pending_closure.sql (1.18ms)4842026/10/01 10:24:12 OK 2_object_stats_trigger.sql (607.66µs)4852026/10/01 10:24:12 OK 3_commit_push.sql (610.05µs)4862026/10/01 10:24:12 goose: up to current file version: 34872026/10/01 10:24:12 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 10:24:12 INFO lead: released remote=192.0.2.1:12344892026/10/01 10:24:13 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 10:24:13 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 10:24:13.072 UTC [575] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 10:24:13.072 UTC [575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 10:24:13 OK 20241026095416_initial_model.sql (6.19ms)4982026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (955.62µs)4992026/10/01 10:24:13 OK 20251218171726_add_pins.sql (2.48ms)5002026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (2.55ms)5012026/10/01 10:24:13 OK 20260905000000_add_claims.sql (2.2ms)5022026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (1.3ms)5032026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (992.01µs)5042026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200005052026/10/01 10:24:13 OK 1_commit_pending_closure.sql (1.41ms)5062026/10/01 10:24:13 OK 2_object_stats_trigger.sql (655.51µs)5072026/10/01 10:24:13 OK 3_commit_push.sql (708.73µs)5082026/10/01 10:24:13 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)510=== RUN TestGCBugBareHashReferences511=== PAUSE TestGCBugBareHashReferences512=== RUN TestGCMetrics513=== PAUSE TestGCMetrics514=== RUN TestPushDedupSurvivesConcurrentGC515=== PAUSE TestPushDedupSurvivesConcurrentGC516=== RUN TestDeduplicatedObjectsRecordedAsPending517=== PAUSE TestDeduplicatedObjectsRecordedAsPending518=== RUN TestGCSweepSkipsPendingObjects519=== PAUSE TestGCSweepSkipsPendingObjects520=== RUN TestTombstonedObjectOfferedWithoutWaiting521=== PAUSE TestTombstonedObjectOfferedWithoutWaiting522=== RUN TestGCSweepDeliversEachKeyOnce523=== PAUSE TestGCSweepDeliversEachKeyOnce524=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== RUN TestForceGCDuringPushOffersSweptObject527=== PAUSE TestForceGCDuringPushOffersSweptObject528=== RUN TestFailedS3DeleteKeepsTombstone529=== PAUSE TestFailedS3DeleteKeepsTombstone530=== RUN TestSweepSkipsRowsLockedByPush531=== PAUSE TestSweepSkipsRowsLockedByPush532=== RUN TestRegisterCompletedObjectNeedsPendingRow533=== PAUSE TestRegisterCompletedObjectNeedsPendingRow534=== RUN TestGetExistingObjectsLocksRows535=== PAUSE TestGetExistingObjectsLocksRows536=== RUN TestSweepRechecksPendingAfterLocking537=== PAUSE TestSweepRechecksPendingAfterLocking538=== RUN TestPushWaitsForSweepHoldingRow539=== PAUSE TestPushWaitsForSweepHoldingRow540=== RUN TestCommitRacingPendingCleanupKeepsObjects541=== PAUSE TestCommitRacingPendingCleanupKeepsObjects542=== RUN TestGCEndsOnShutdown543=== PAUSE TestGCEndsOnShutdown544=== RUN TestGCTaskStore_StartNew545=== PAUSE TestGCTaskStore_StartNew546=== RUN TestGCTaskStore_DeduplicateSameParams547=== PAUSE TestGCTaskStore_DeduplicateSameParams548=== RUN TestGCTaskStore_ConflictDifferentParams549=== PAUSE TestGCTaskStore_ConflictDifferentParams550=== RUN TestGCTaskStore_GetEmpty551=== PAUSE TestGCTaskStore_GetEmpty552=== RUN TestGCTaskStore_GetReturnsLatest553=== PAUSE TestGCTaskStore_GetReturnsLatest554=== RUN TestGCTaskStore_CompletedAllowsNewTask555=== PAUSE TestGCTaskStore_CompletedAllowsNewTask556=== RUN TestGCTaskStore_PhaseUpdates557=== PAUSE TestGCTaskStore_PhaseUpdates558=== RUN TestGCTaskStore_Fail559=== PAUSE TestGCTaskStore_Fail560=== RUN TestGracefulShutdownDrainsInflight561=== PAUSE TestGracefulShutdownDrainsInflight562=== RUN TestService_healthCheckHandler563=== PAUSE TestService_healthCheckHandler564=== RUN TestService_readinessHandler565=== PAUSE TestService_readinessHandler566=== RUN TestGenerateLandingPage567=== PAUSE TestGenerateLandingPage568=== RUN TestCacheConfigHandlerMaxNarSize569=== PAUSE TestCacheConfigHandlerMaxNarSize570=== RUN TestCreatePendingClosureRejectsOversizedNAR571=== PAUSE TestCreatePendingClosureRejectsOversizedNAR572=== RUN TestNARDeduplicationMetadataUploadBug573=== PAUSE TestNARDeduplicationMetadataUploadBug574=== RUN TestMetricsInventory575=== PAUSE TestMetricsInventory576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestOrphanedObjectsGC589=== PAUSE TestOrphanedObjectsGC590=== RUN TestOrphanedObjectsGCStressTest591=== PAUSE TestOrphanedObjectsGCStressTest592=== RUN TestCreatePin_ReservedPins593=== PAUSE TestCreatePin_ReservedPins594=== RUN TestPresentReportsOnlyClosureRoots595=== PAUSE TestPresentReportsOnlyClosureRoots596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyOutlastsServerWriteTimeout617=== PAUSE TestReadProxyOutlastsServerWriteTimeout618=== RUN TestReadProxyConditionalGet619=== PAUSE TestReadProxyConditionalGet620=== RUN TestReadProxyRootRedirectsToIndexHTML621=== PAUSE TestReadProxyRootRedirectsToIndexHTML622=== RUN TestReadProxyDisabled623=== PAUSE TestReadProxyDisabled624=== RUN TestReadRedirectNar625=== PAUSE TestReadRedirectNar626=== RUN TestReadRedirectKeepsNarinfoProxied627=== PAUSE TestReadRedirectKeepsNarinfoProxied628=== RUN TestReadProxyRangeRequest629=== PAUSE TestReadProxyRangeRequest630=== RUN TestReadRedirectUsesPublicS3URL631=== PAUSE TestReadRedirectUsesPublicS3URL632=== RUN TestPush_OverlappingRootsStoreOneRowPerKey633=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey634=== RUN TestPush_CompleteCommitsEveryRoot635=== PAUSE TestPush_CompleteCommitsEveryRoot636=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit637=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit638=== RUN TestPush_RejectsBadRequests639=== PAUSE TestPush_RejectsBadRequests640=== RUN TestPush_SignsNarinfosOfItsPendingObjects641=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects642=== RUN TestRedundantMultipartUpload643=== PAUSE TestRedundantMultipartUpload644=== RUN TestCompleteMultipartUpload_ErrorButObjectExists645=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists646=== RUN TestCompletedNarNotReofferedAcrossClosures647=== PAUSE TestCompletedNarNotReofferedAcrossClosures648=== RUN TestPresignedUploadRegisteredBeforeCommit649=== PAUSE TestPresignedUploadRegisteredBeforeCommit650=== RUN TestService_Rustfstest651=== PAUSE TestService_Rustfstest652=== RUN TestParseSize653=== PAUSE TestParseSize654=== RUN TestSkippedUploadsHandler655=== PAUSE TestSkippedUploadsHandler656=== RUN TestSystemdListenerNotActivated657--- PASS: TestSystemdListenerNotActivated (0.00s)658=== RUN TestWatchdogBeatsWhenHealthy659--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)660=== RUN TestWatchdogSkipsWhenUnhealthy6612026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/01 10:24:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"671--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)672=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle673=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle674=== RUN TestProxyWriteTimeout675=== PAUSE TestProxyWriteTimeout676=== RUN TestPendingClosureWriteTimeout677=== PAUSE TestPendingClosureWriteTimeout678=== RUN TestIsValidUploadKey679=== PAUSE TestIsValidUploadKey680=== RUN TestUploadHandlersRejectInvalidKeys681=== PAUSE TestUploadHandlersRejectInvalidKeys682=== RUN TestUploadHandlersRejectOversizedBody683=== PAUSE TestUploadHandlersRejectOversizedBody684=== RUN TestService_cleanupPendingClosuresHandler685=== PAUSE TestService_cleanupPendingClosuresHandler686=== RUN TestService_createPendingClosureHandler687=== PAUSE TestService_createPendingClosureHandler688=== RUN TestService_verifyS3Integrity689=== PAUSE TestService_verifyS3Integrity690=== RUN TestCompleteMultipartUnregistered691=== PAUSE TestCompleteMultipartUnregistered692=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT693=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT694=== CONT TestService_AuthMiddleware695=== CONT TestParseSize696=== CONT TestCompleteMultipartUnregistered697=== CONT TestGCSweepSkipsPendingObjects698=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT699=== CONT TestCreatePendingClosureRejectsOversizedNAR700=== CONT TestService_verifyS3Integrity701=== CONT TestService_createPendingClosureHandler7022026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures703=== CONT TestService_cleanupPendingClosuresHandler704=== CONT TestUploadHandlersRejectOversizedBody705=== CONT TestUploadHandlersRejectInvalidKeys706=== CONT TestIsValidUploadKey707=== CONT TestPendingClosureWriteTimeout708=== CONT TestProxyWriteTimeout709=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle710=== RUN TestIsValidUploadKey/narinfo711=== PAUSE TestIsValidUploadKey/narinfo712=== RUN TestIsValidUploadKey/nar_zst713=== PAUSE TestIsValidUploadKey/nar_zst714=== RUN TestIsValidUploadKey/nar_xz715=== PAUSE TestIsValidUploadKey/nar_xz716=== RUN TestIsValidUploadKey/nar_plain717=== PAUSE TestIsValidUploadKey/nar_plain718=== RUN TestIsValidUploadKey/listing719=== PAUSE TestIsValidUploadKey/listing720=== RUN TestIsValidUploadKey/build_log721=== PAUSE TestIsValidUploadKey/build_log722=== RUN TestIsValidUploadKey/build_log_home-manager_file723=== PAUSE TestIsValidUploadKey/build_log_home-manager_file724=== RUN TestIsValidUploadKey/build_log_plus_in_name725=== PAUSE TestIsValidUploadKey/build_log_plus_in_name726=== RUN TestIsValidUploadKey/build_log_question_mark727=== PAUSE TestIsValidUploadKey/build_log_question_mark728=== RUN TestPendingClosureWriteTimeout/empty729=== CONT TestCacheConfigHandlerMaxNarSize730=== CONT TestGenerateLandingPage731=== CONT TestService_readinessHandler732=== CONT TestService_healthCheckHandler733=== CONT TestGCTaskStore_ConflictDifferentParams734=== CONT TestGracefulShutdownDrainsInflight735=== CONT TestGCTaskStore_Fail736=== CONT TestGCTaskStore_PhaseUpdates737=== CONT TestGCTaskStore_CompletedAllowsNewTask738--- PASS: TestParseSize (0.00s)739=== CONT TestGCTaskStore_GetReturnsLatest740=== CONT TestGCTaskStore_GetEmpty741=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info742=== RUN TestProxyWriteTimeout/narinfo743=== CONT TestSkippedUploadsHandler744=== RUN TestIsValidUploadKey/build_log_equals745=== PAUSE TestPendingClosureWriteTimeout/empty746--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)747=== RUN TestPendingClosureWriteTimeout/400_objects748=== PAUSE TestPendingClosureWriteTimeout/400_objects749=== RUN TestPendingClosureWriteTimeout/670k_objects750--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)751--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)752--- PASS: TestGenerateLandingPage (0.01s)753=== CONT TestGCTaskStore_StartNew754--- PASS: TestGCTaskStore_StartNew (0.00s)755=== CONT TestGCEndsOnShutdown756=== CONT TestGCTaskStore_DeduplicateSameParams757--- PASS: TestGCTaskStore_GetEmpty (0.00s)758=== CONT TestCommitRacingPendingCleanupKeepsObjects759=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info760=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal761=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal762=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key763=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key7642026/10/01 10:24:13 INFO Starting HTTP server address=127.0.0.1:40405765=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key766=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key767=== PAUSE TestProxyWriteTimeout/narinfo7682026/10/01 10:24:13 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000769=== RUN TestProxyWriteTimeout/1_GiB_nar770=== PAUSE TestIsValidUploadKey/build_log_equals771=== PAUSE TestPendingClosureWriteTimeout/670k_objects772--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)773=== CONT TestPushWaitsForSweepHoldingRow7742026/10/01 10:24:13 INFO Shutdown signal received, draining in-flight requests timeout=10s775=== CONT TestSweepRechecksPendingAfterLocking776=== CONT TestGetExistingObjectsLocksRows777=== CONT TestRegisterCompletedObjectNeedsPendingRow778=== CONT TestSweepSkipsRowsLockedByPush779=== CONT TestFailedS3DeleteKeepsTombstone780=== RUN TestIsValidUploadKey/realisation781=== PAUSE TestIsValidUploadKey/realisation782=== RUN TestIsValidUploadKey/realisation_plus_in_output783=== PAUSE TestIsValidUploadKey/realisation_plus_in_output784=== RUN TestIsValidUploadKey/nix-cache-info785=== PAUSE TestIsValidUploadKey/nix-cache-info786=== RUN TestIsValidUploadKey/index.html787=== PAUSE TestIsValidUploadKey/index.html788=== RUN TestIsValidUploadKey/narinfo_key,_nar_type789=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type790--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)791--- PASS: TestGCTaskStore_Fail (0.00s)792=== PAUSE TestProxyWriteTimeout/1_GiB_nar793=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline794=== RUN TestIsValidUploadKey/nar_key,_narinfo_type795=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type796=== RUN TestIsValidUploadKey/listing_key,_narinfo_type797--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)798--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)799=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline800=== RUN TestProxyWriteTimeout/10_GiB_nar801=== PAUSE TestProxyWriteTimeout/10_GiB_nar802=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type803=== CONT TestForceGCDuringPushOffersSweptObject804=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows805=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows806=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check807=== RUN TestProxyWriteTimeout/unknown_size808=== PAUSE TestProxyWriteTimeout/unknown_size809=== RUN TestIsValidUploadKey/traversal810=== PAUSE TestIsValidUploadKey/traversal811=== RUN TestIsValidUploadKey/traversal_nar812=== PAUSE TestIsValidUploadKey/traversal_nar813=== RUN TestIsValidUploadKey/absolute814=== PAUSE TestIsValidUploadKey/absolute815=== RUN TestIsValidUploadKey/empty_key816=== PAUSE TestIsValidUploadKey/empty_key817=== RUN TestIsValidUploadKey/unknown_type818=== PAUSE TestIsValidUploadKey/unknown_type819=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check820=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection821=== CONT TestGCSweepDeliversEachKeyOnce822=== CONT TestTombstonedObjectOfferedWithoutWaiting823--- PASS: TestSkippedUploadsHandler (0.01s)824=== CONT TestReadProxyInvalidPath825--- PASS: TestGracefulShutdownDrainsInflight (0.23s)826=== CONT TestService_Rustfstest8272026-10-01 10:24:13.613 UTC [635] ERROR: relation "goose_db_version" does not exist at character 368282026-10-01 10:24:13.613 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026-10-01 10:24:13.614 UTC [638] ERROR: relation "goose_db_version" does not exist at character 368302026-10-01 10:24:13.614 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-10-01 10:24:13.614 UTC [637] ERROR: relation "goose_db_version" does not exist at character 368322026-10-01 10:24:13.614 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-10-01 10:24:13.616 UTC [639] ERROR: relation "goose_db_version" does not exist at character 368342026-10-01 10:24:13.616 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026-10-01 10:24:13.616 UTC [640] ERROR: relation "goose_db_version" does not exist at character 368362026-10-01 10:24:13.616 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC837=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure8382026-10-01 10:24:13.617 UTC [642] ERROR: relation "goose_db_version" does not exist at character 368392026-10-01 10:24:13.617 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC840=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure841=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart842=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart843=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts844=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts845=== CONT TestPresignedUploadRegisteredBeforeCommit8462026-10-01 10:24:13.618 UTC [643] ERROR: relation "goose_db_version" does not exist at character 368472026-10-01 10:24:13.618 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026-10-01 10:24:13.626 UTC [644] ERROR: relation "goose_db_version" does not exist at character 368492026-10-01 10:24:13.626 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026-10-01 10:24:13.631 UTC [647] ERROR: relation "goose_db_version" does not exist at character 368512026-10-01 10:24:13.631 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8522026-10-01 10:24:13.640 UTC [648] ERROR: relation "goose_db_version" does not exist at character 368532026-10-01 10:24:13.640 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026-10-01 10:24:13.643 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368552026-10-01 10:24:13.643 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026/10/01 10:24:13 OK 20241026095416_initial_model.sql (38.5ms)8572026/10/01 10:24:13 OK 20241026095416_initial_model.sql (36.56ms)8582026/10/01 10:24:13 OK 20241026095416_initial_model.sql (34.96ms)8592026/10/01 10:24:13 OK 20241026095416_initial_model.sql (37.73ms)8602026/10/01 10:24:13 OK 20241026095416_initial_model.sql (39.98ms)8612026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (6.53ms)8622026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (5.16ms)8632026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (5.23ms)8642026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)8652026/10/01 10:24:13 OK 20241026095416_initial_model.sql (41.14ms)8662026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)8672026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)8682026/10/01 10:24:13 OK 20241026095416_initial_model.sql (45.04ms)8692026/10/01 10:24:13 OK 20241026095416_initial_model.sql (47.01ms)8702026/10/01 10:24:13 OK 20241026095416_initial_model.sql (44.29ms)8712026/10/01 10:24:13 OK 20251218171726_add_pins.sql (6.36ms)8722026/10/01 10:24:13 OK 20251218171726_add_pins.sql (7.06ms)8732026/10/01 10:24:13 OK 20251218171726_add_pins.sql (8.6ms)8742026/10/01 10:24:13 OK 20251218171726_add_pins.sql (8.93ms)8752026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (3.99ms)8762026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (3.78ms)8772026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (3.87ms)8782026/10/01 10:24:13 OK 20251218171726_add_pins.sql (6.39ms)8792026/10/01 10:24:13 OK 20241026095416_initial_model.sql (28.98ms)8802026/10/01 10:24:13 OK 20241026095416_initial_model.sql (31.07ms)8812026/10/01 10:24:13 OK 20251218171726_add_pins.sql (11.09ms)8822026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (3.93ms)8832026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (6.56ms)8842026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (6.87ms)8852026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (4.94ms)8862026/10/01 10:24:13 OK 20251218171726_add_pins.sql (6.04ms)8872026/10/01 10:24:13 OK 20251218171726_add_pins.sql (6.26ms)8882026/10/01 10:24:13 OK 20251218171726_add_pins.sql (8.09ms)8892026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (9.69ms)8902026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (9.45ms)8912026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (10.63ms)8922026/10/01 10:24:13 OK 20251218171726_add_pins.sql (6.38ms)8932026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (6.13ms)8942026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (6.25ms)8952026/10/01 10:24:13 OK 20260905000000_add_claims.sql (7.26ms)8962026/10/01 10:24:13 OK 20251218171726_add_pins.sql (6.51ms)8972026/10/01 10:24:13 OK 20260905000000_add_claims.sql (7.34ms)8982026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (11.31ms)8992026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (6.89ms)9002026/10/01 10:24:13 OK 20260905000000_add_claims.sql (4.58ms)9012026/10/01 10:24:13 OK 20260905000000_add_claims.sql (5.53ms)9022026/10/01 10:24:13 OK 20260905000000_add_claims.sql (5.62ms)9032026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (4.05ms)9042026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3.95ms)9052026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (5.84ms)9062026/10/01 10:24:13 OK 20260905000000_add_claims.sql (5.92ms)9072026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (4.17ms)9082026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (17.07ms)9092026/10/01 10:24:13 OK 20260905000000_add_claims.sql (17.3ms)9102026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (14.68ms)9112026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (15.71ms)9122026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (15.12ms)9132026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009142026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (17.45ms)9152026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009162026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (17.27ms)9172026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009182026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (16.78ms)9192026/10/01 10:24:13 OK 20260905000000_add_claims.sql (17.16ms)9202026/10/01 10:24:13 OK 20260905000000_add_claims.sql (20.83ms)9212026/10/01 10:24:13 OK 20260905000000_add_claims.sql (19.58ms)9222026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (7.9ms)9232026/10/01 10:24:13 OK 1_commit_pending_closure.sql (3.36ms)9242026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (7.24ms)9252026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009262026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.73ms)9272026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009282026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (7.12ms)9292026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009302026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3.67ms)9312026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3.9ms)9322026/10/01 10:24:13 OK 1_commit_pending_closure.sql (4.87ms)9332026/10/01 10:24:13 OK 1_commit_pending_closure.sql (5.12ms)9342026/10/01 10:24:13 OK 20260905000000_add_claims.sql (10.1ms)9352026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (5.72ms)9362026/10/01 10:24:13 OK 2_object_stats_trigger.sql (3.86ms)9372026/10/01 10:24:13 OK 2_object_stats_trigger.sql (4.93ms)9382026/10/01 10:24:13 OK 1_commit_pending_closure.sql (6.33ms)9392026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (6.09ms)9402026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009412026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (7.2ms)9422026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009432026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (5.72ms)9442026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009452026/10/01 10:24:13 OK 1_commit_pending_closure.sql (6.53ms)9462026/10/01 10:24:13 OK 1_commit_pending_closure.sql (6.83ms)9472026/10/01 10:24:13 OK 2_object_stats_trigger.sql (5.05ms)9482026/10/01 10:24:13 OK 3_commit_push.sql (5.69ms)9492026/10/01 10:24:13 goose: up to current file version: 39502026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (6.44ms)9512026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009522026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (8.1ms)9532026/10/01 10:24:13 OK 2_object_stats_trigger.sql (4.21ms)9542026/10/01 10:24:13 OK 2_object_stats_trigger.sql (3.17ms)9552026/10/01 10:24:13 OK 3_commit_push.sql (4.37ms)9562026/10/01 10:24:13 goose: up to current file version: 39572026/10/01 10:24:13 OK 1_commit_pending_closure.sql (3.9ms)9582026/10/01 10:24:13 OK 3_commit_push.sql (3.07ms)9592026/10/01 10:24:13 goose: up to current file version: 39602026/10/01 10:24:13 OK 2_object_stats_trigger.sql (3.31ms)9612026/10/01 10:24:13 OK 1_commit_pending_closure.sql (5ms)9622026/10/01 10:24:13 OK 1_commit_pending_closure.sql (5.57ms)9632026/10/01 10:24:13 OK 3_commit_push.sql (3.37ms)9642026/10/01 10:24:13 goose: up to current file version: 39652026/10/01 10:24:13 OK 2_object_stats_trigger.sql (2.99ms)9662026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (4.62ms)9672026/10/01 10:24:13 goose: successfully migrated database to version: 202609231200009682026/10/01 10:24:13 OK 3_commit_push.sql (2.76ms)9692026/10/01 10:24:13 goose: up to current file version: 39702026/10/01 10:24:13 OK 1_commit_pending_closure.sql (4.91ms)9712026/10/01 10:24:13 OK 3_commit_push.sql (3.32ms)9722026/10/01 10:24:13 goose: up to current file version: 39732026/10/01 10:24:13 OK 2_object_stats_trigger.sql (3.01ms)9742026/10/01 10:24:13 OK 2_object_stats_trigger.sql (3.11ms)9752026/10/01 10:24:13 OK 3_commit_push.sql (2.57ms)9762026/10/01 10:24:13 goose: up to current file version: 39772026/10/01 10:24:13 OK 3_commit_push.sql (14.15ms)9782026/10/01 10:24:13 goose: up to current file version: 39792026/10/01 10:24:13 OK 1_commit_pending_closure.sql (15.21ms)9802026/10/01 10:24:13 OK 2_object_stats_trigger.sql (14.88ms)9812026/10/01 10:24:13 OK 3_commit_push.sql (14.07ms)9822026/10/01 10:24:13 goose: up to current file version: 3983--- PASS: TestService_healthCheckHandler (0.40s)984=== CONT TestCompletedNarNotReofferedAcrossClosures9852026/10/01 10:24:13 OK 2_object_stats_trigger.sql (5.26ms)9862026/10/01 10:24:13 OK 3_commit_push.sql (6.2ms)9872026/10/01 10:24:13 goose: up to current file version: 39882026/10/01 10:24:13 OK 3_commit_push.sql (1.76ms)9892026/10/01 10:24:13 goose: up to current file version: 39902026-10-01 10:24:13.776 UTC [657] ERROR: relation "goose_db_version" does not exist at character 369912026-10-01 10:24:13.776 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9922026-10-01 10:24:13.777 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369932026-10-01 10:24:13.777 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9942026-10-01 10:24:13.777 UTC [658] ERROR: relation "goose_db_version" does not exist at character 369952026-10-01 10:24:13.777 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9962026-10-01 10:24:13.777 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369972026-10-01 10:24:13.777 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9982026-10-01 10:24:13.782 UTC [661] ERROR: relation "goose_db_version" does not exist at character 369992026-10-01 10:24:13.782 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10002026-10-01 10:24:13.783 UTC [664] ERROR: relation "goose_db_version" does not exist at character 3610012026-10-01 10:24:13.783 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10022026-10-01 10:24:13.783 UTC [662] ERROR: relation "goose_db_version" does not exist at character 3610032026-10-01 10:24:13.783 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10042026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures10052026-10-01 10:24:13.795 UTC [665] ERROR: relation "goose_db_version" does not exist at character 3610062026-10-01 10:24:13.795 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10072026-10-01 10:24:13.797 UTC [666] ERROR: relation "goose_db_version" does not exist at character 3610082026-10-01 10:24:13.797 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10092026/10/01 10:24:13 OK 20241026095416_initial_model.sql (11.34ms)10102026/10/01 10:24:13 OK 20241026095416_initial_model.sql (11.4ms)10112026/10/01 10:24:13 OK 20241026095416_initial_model.sql (12.82ms)10122026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)10132026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)10142026/10/01 10:24:13 OK 20241026095416_initial_model.sql (11.11ms)10152026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (3.37ms)10162026/10/01 10:24:13 OK 20241026095416_initial_model.sql (12.45ms)10172026/10/01 10:24:13 OK 20241026095416_initial_model.sql (11.3ms)10182026-10-01 10:24:13.802 UTC [667] ERROR: relation "goose_db_version" does not exist at character 3610192026-10-01 10:24:13.802 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10202026/10/01 10:24:13 OK 20241026095416_initial_model.sql (15.4ms)10212026/10/01 10:24:13 OK 20251218171726_add_pins.sql (3.57ms)10222026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)10232026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)10242026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)10252026/10/01 10:24:13 OK 20251218171726_add_pins.sql (2.58ms)10262026/10/01 10:24:13 OK 20251218171726_add_pins.sql (3.56ms)10272026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)10282026-10-01 10:24:13.805 UTC [668] ERROR: relation "goose_db_version" does not exist at character 3610292026-10-01 10:24:13.805 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10302026-10-01 10:24:13.805 UTC [669] ERROR: relation "goose_db_version" does not exist at character 3610312026-10-01 10:24:13.805 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10322026-10-01 10:24:13.806 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3610332026-10-01 10:24:13.806 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10342026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures10352026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures10372026/10/01 10:24:13 OK 20251218171726_add_pins.sql (4.64ms)10382026/10/01 10:24:13 OK 20251218171726_add_pins.sql (5.44ms)10392026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (5.9ms)10402026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)10412026/10/01 10:24:13 OK 20251218171726_add_pins.sql (5.69ms)10422026/10/01 10:24:13 OK 20251218171726_add_pins.sql (4.48ms)10432026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)10442026/10/01 10:24:13 OK 20260905000000_add_claims.sql (4.08ms)10452026/10/01 10:24:13 OK 20260905000000_add_claims.sql (4.41ms)10462026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (5.43ms)10472026/10/01 10:24:13 OK 20260905000000_add_claims.sql (4.32ms)10482026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)10492026/10/01 10:24:13 INFO Aborted multipart uploads count=0 kept=010502026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (5.5ms)10512026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (6.84ms)10522026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3ms)10532026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.97ms)10542026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3.12ms)10552026/10/01 10:24:13 OK 20260905000000_add_claims.sql (3.27ms)10562026/10/01 10:24:13 OK 20241026095416_initial_model.sql (14.43ms)10572026/10/01 10:24:13 OK 20260905000000_add_claims.sql (4.24ms)10582026/10/01 10:24:13 WARN Force mode enabled - objects will be deleted immediately without grace period10592026/10/01 10:24:13 OK 20241026095416_initial_model.sql (13.37ms)10602026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.43ms)10612026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)10622026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000010632026/10/01 10:24:13 OK 20260905000000_add_claims.sql (4.22ms)10642026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.43ms)10652026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000010662026/10/01 10:24:13 OK 20241026095416_initial_model.sql (9.6ms)10672026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.49ms)10682026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000010692026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.82ms)10702026/10/01 10:24:13 OK 20260905000000_add_claims.sql (3.99ms)10712026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)10722026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.51ms)10732026/10/01 10:24:13 OK 20241026095416_initial_model.sql (9.29ms)10742026/10/01 10:24:13 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=010752026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.34ms)10762026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.5ms)10772026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.65ms)10782026/10/01 10:24:13 OK 20241026095416_initial_model.sql (10.32ms)10792026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)10802026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.68ms)10812026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3.36ms)10822026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.33ms)10832026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000010842026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)10852026/10/01 10:24:13 OK 20251218171726_add_pins.sql (3.69ms)10862026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (3.16ms)10872026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000010882026/10/01 10:24:13 OK 20251218171726_add_pins.sql (2.94ms)10892026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.75ms)10902026/10/01 10:24:13 OK 20241026095416_initial_model.sql (9.85ms)10912026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.65ms)10922026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.71ms)10932026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)10942026/10/01 10:24:13 INFO Vacuumed table table=pending_closures10952026/10/01 10:24:13 OK 20251218171726_add_pins.sql (3.33ms)10962026/10/01 10:24:13 OK 3_commit_push.sql (1.6ms)10972026/10/01 10:24:13 goose: up to current file version: 310982026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.69ms)10992026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011002026/10/01 10:24:13 OK 3_commit_push.sql (1.47ms)11012026/10/01 10:24:13 goose: up to current file version: 311022026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.86ms)11032026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011042026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.37ms)11052026/10/01 10:24:13 OK 3_commit_push.sql (1.81ms)11062026/10/01 10:24:13 goose: up to current file version: 311072026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)11082026/10/01 10:24:13 OK 1_commit_pending_closure.sql (3.07ms)11092026/10/01 10:24:13 OK 20251218171726_add_pins.sql (3.05ms)11102026/10/01 10:24:13 OK 20251218171726_add_pins.sql (2.82ms)11112026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)11122026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)11132026/10/01 10:24:13 INFO Vacuumed table table=pending_objects11142026/10/01 10:24:13 INFO Vacuumed table table=multipart_uploads11152026/10/01 10:24:13 INFO Vacuumed table table=closures11162026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.6ms)11172026/10/01 10:24:13 OK 2_object_stats_trigger.sql (2.51ms)11182026/10/01 10:24:13 OK 2_object_stats_trigger.sql (2.12ms)11192026/10/01 10:24:13 OK 20251218171726_add_pins.sql (3.25ms)11202026/10/01 10:24:13 OK 1_commit_pending_closure.sql (3.96ms)11212026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)11222026/10/01 10:24:13 OK 20260905000000_add_claims.sql (3.69ms)11232026/10/01 10:24:13 OK 20260905000000_add_claims.sql (3.78ms)11242026/10/01 10:24:13 OK 3_commit_push.sql (1.56ms)11252026/10/01 10:24:13 goose: up to current file version: 311262026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)11272026/10/01 10:24:13 OK 3_commit_push.sql (1.74ms)11282026/10/01 10:24:13 goose: up to current file version: 311292026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.89ms)11302026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)11312026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.68ms)11322026/10/01 10:24:13 INFO Vacuumed table table=objects11332026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.94ms)11342026/10/01 10:24:13 OK 3_commit_push.sql (9.05ms)11352026/10/01 10:24:13 goose: up to current file version: 311362026/10/01 10:24:13 OK 3_commit_push.sql (9.35ms)11372026/10/01 10:24:13 goose: up to current file version: 311382026/10/01 10:24:13 OK 20260905000000_add_claims.sql (10.94ms)11392026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (11.14ms)11402026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (10.53ms)11412026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (8ms)11422026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011432026/10/01 10:24:13 OK 20260905000000_add_claims.sql (10.61ms)11442026/10/01 10:24:13 OK 20260905000000_add_claims.sql (10.23ms)11452026/10/01 10:24:13 INFO Received cleanup request method=DELETE path=/api/pending_closures1146--- PASS: TestGCSweepSkipsPendingObjects (0.49s)1147=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11482026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.27ms)11492026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.18ms)11502026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011512026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.56ms)11522026/10/01 10:24:13 OK 20260905000000_add_claims.sql (3.28ms)11532026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3.07ms)11542026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (3ms)11552026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.39ms)11562026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011572026/10/01 10:24:13 INFO Aborted multipart uploads count=0 kept=011582026/10/01 10:24:13 OK 1_commit_pending_closure.sql (3.01ms)11592026/10/01 10:24:13 OK 2_object_stats_trigger.sql (2.31ms)11602026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.82ms)11612026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.56ms)11622026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (2.71ms)11632026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011642026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011652026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.24ms)11662026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.36ms)11672026/10/01 10:24:13 OK 3_commit_push.sql (1.19ms)11682026/10/01 10:24:13 goose: up to current file version: 311692026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (1.8ms)11702026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000011712026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures11722026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.85ms)11732026/10/01 10:24:13 OK 3_commit_push.sql (1.74ms)11742026/10/01 10:24:13 goose: up to current file version: 311752026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.75ms)11762026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.61ms)11772026/10/01 10:24:13 OK 3_commit_push.sql (968.37µs)11782026/10/01 10:24:13 goose: up to current file version: 311792026/10/01 10:24:13 OK 1_commit_pending_closure.sql (1.81ms)11802026/10/01 10:24:13 OK 2_object_stats_trigger.sql (915.33µs)11812026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.26ms)11822026/10/01 10:24:13 OK 2_object_stats_trigger.sql (1.03ms)11832026/10/01 10:24:13 OK 3_commit_push.sql (774.57µs)11842026/10/01 10:24:13 goose: up to current file version: 311852026/10/01 10:24:13 OK 3_commit_push.sql (1.22ms)11862026/10/01 10:24:13 goose: up to current file version: 311872026/10/01 10:24:13 OK 3_commit_push.sql (1.89ms)11882026/10/01 10:24:13 goose: up to current file version: 311892026/10/01 10:24:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11902026-10-01 10:24:13.870 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3611912026-10-01 10:24:13.870 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/10/01 10:24:13 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1193--- PASS: TestCompleteMultipartUnregistered (0.52s)1194=== CONT TestRedundantMultipartUpload11952026/10/01 10:24:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11962026/10/01 10:24:13 INFO Aborted multipart uploads count=1 kept=011972026/10/01 10:24:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11982026-10-01 10:24:13.887 UTC [637] ERROR: Closure does not exist: id=111992026-10-01 10:24:13.887 UTC [637] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12002026-10-01 10:24:13.887 UTC [637] STATEMENT: -- name: CommitPendingClosure :exec1201 SELECT commit_pending_closure($1::bigint)1202 1203--- PASS: TestService_cleanupPendingClosuresHandler (0.53s)1204=== CONT TestPush_SignsNarinfosOfItsPendingObjects12052026/10/01 10:24:13 OK 20241026095416_initial_model.sql (8.48ms)12062026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)12072026/10/01 10:24:13 OK 20251218171726_add_pins.sql (3.14ms)12082026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (2.93ms)12092026/10/01 10:24:13 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1210--- PASS: TestService_AuthMiddleware (0.55s)1211=== CONT TestPush_RejectsBadRequests12122026/10/01 10:24:13 OK 20260905000000_add_claims.sql (3.49ms)12132026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.06ms)12142026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (1.95ms)12152026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000012162026/10/01 10:24:13 OK 1_commit_pending_closure.sql (2.56ms)12172026/10/01 10:24:13 OK 2_object_stats_trigger.sql (2.61ms)12182026/10/01 10:24:13 OK 3_commit_push.sql (1.35ms)12192026/10/01 10:24:13 goose: up to current file version: 312202026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures12212026-10-01 10:24:13.936 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3612222026-10-01 10:24:13.936 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12232026/10/01 10:24:13 OK 20241026095416_initial_model.sql (10.98ms)12242026/10/01 10:24:13 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)12252026/10/01 10:24:13 OK 20251218171726_add_pins.sql (4.26ms)12262026/10/01 10:24:13 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)1227--- PASS: TestGCEndsOnShutdown (0.60s)1228=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit12292026/10/01 10:24:13 OK 20260905000000_add_claims.sql (3.61ms)12302026/10/01 10:24:13 OK 20260920000000_drop_claims.sql (2.34ms)12312026/10/01 10:24:13 OK 20260923120000_add_pushes.sql (1.87ms)12322026/10/01 10:24:13 goose: successfully migrated database to version: 2026092312000012332026/10/01 10:24:13 INFO Received uploads request method=POST path=/api/pending_closures12342026/10/01 10:24:13 OK 1_commit_pending_closure.sql (10.71ms)12352026/10/01 10:24:13 OK 2_object_stats_trigger.sql (2.33ms)12362026/10/01 10:24:13 OK 3_commit_push.sql (1.18ms)12372026/10/01 10:24:13 goose: up to current file version: 31238--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.64s)1239=== CONT TestPush_CompleteCommitsEveryRoot12402026-10-01 10:24:13.999 UTC [685] ERROR: relation "goose_db_version" does not exist at character 3612412026-10-01 10:24:13.999 UTC [685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12422026-10-01 10:24:13.999 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3612432026-10-01 10:24:13.999 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12442026-10-01 10:24:14.000 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3612452026-10-01 10:24:14.000 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026/10/01 10:24:14 WARN readiness check failed error="closed pool"1247--- PASS: TestService_readinessHandler (0.65s)1248=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12492026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.38ms)12502026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.66ms)12512026/10/01 10:24:14 OK 20241026095416_initial_model.sql (10.55ms)12522026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2ms)12532026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)12542026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)12552026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.01ms)12562026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.68ms)12572026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.69ms)12582026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)12592026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)12602026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)12612026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.85ms)12622026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.55ms)12632026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.65ms)12642026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (3.03ms)12652026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (3.25ms)12662026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (3.26ms)12672026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.84ms)12682026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000012692026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.41ms)12702026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000012712026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.09ms)12722026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000012732026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.68ms)12742026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.87ms)12752026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.05ms)12762026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.9ms)12772026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.64ms)12782026/10/01 10:24:14 OK 3_commit_push.sql (1.39ms)12792026/10/01 10:24:14 goose: up to current file version: 312802026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures12812026/10/01 10:24:14 OK 3_commit_push.sql (1.8ms)12822026/10/01 10:24:14 goose: up to current file version: 312832026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.03ms)12842026/10/01 10:24:14 OK 3_commit_push.sql (1.44ms)12852026/10/01 10:24:14 goose: up to current file version: 31286--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.54s)1287=== CONT TestReadRedirectUsesPublicS3URL12882026-10-01 10:24:14.076 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3612892026-10-01 10:24:14.076 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.54ms)12912026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)12922026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.86ms)12932026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures12942026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)12952026-10-01 10:24:14.104 UTC [695] ERROR: relation "goose_db_version" does not exist at character 3612962026-10-01 10:24:14.104 UTC [695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12972026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.1ms)12982026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (1.57ms)12992026-10-01 10:24:14.108 UTC [696] ERROR: relation "goose_db_version" does not exist at character 3613002026-10-01 10:24:14.108 UTC [696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13012026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2ms)13022026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000013032026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.55ms)13042026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.03ms)13052026/10/01 10:24:14 OK 3_commit_push.sql (8.35ms)13062026/10/01 10:24:14 goose: up to current file version: 313072026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.18ms)13082026/10/01 10:24:14 OK 20241026095416_initial_model.sql (13.59ms)13092026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)13102026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)13112026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.91ms)13122026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.75ms)13132026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)13142026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)13152026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.42ms)13162026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.52ms)13172026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.41ms)13182026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (3.24ms)13192026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.52ms)13202026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000013212026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.95ms)13222026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000013232026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.53ms)13242026/10/01 10:24:14 OK 1_commit_pending_closure.sql (1.43ms)13252026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.01ms)13262026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.53ms)13272026/10/01 10:24:14 OK 3_commit_push.sql (1.44ms)13282026/10/01 10:24:14 goose: up to current file version: 313292026/10/01 10:24:14 OK 3_commit_push.sql (942.57µs)13302026/10/01 10:24:14 goose: up to current file version: 313312026/10/01 10:24:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13322026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=013332026-10-01 10:24:14.172 UTC [700] ERROR: relation "goose_db_version" does not exist at character 3613342026-10-01 10:24:14.172 UTC [700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13352026/10/01 10:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/10/01 10:24:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013372026/10/01 10:24:14 INFO Vacuumed table table=pending_closures13382026/10/01 10:24:14 INFO Vacuumed table table=pending_objects13392026/10/01 10:24:14 INFO Vacuumed table table=multipart_uploads13402026/10/01 10:24:14 OK 20241026095416_initial_model.sql (7.31ms)13412026/10/01 10:24:14 INFO Vacuumed table table=closures13422026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)13432026/10/01 10:24:14 INFO Vacuumed table table=objects13442026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.57ms)13452026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=013462026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (2.87ms)13472026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures1348--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.66s)1349=== CONT TestReadProxyRangeRequest13502026/10/01 10:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period13512026/10/01 10:24:14 OK 20260905000000_add_claims.sql (2.68ms)13522026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.21ms)13532026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.7ms)13542026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000013552026/10/01 10:24:14 OK 1_commit_pending_closure.sql (1.54ms)13562026/10/01 10:24:14 OK 2_object_stats_trigger.sql (837.1µs)13572026/10/01 10:24:14 OK 3_commit_push.sql (868.67µs)13582026/10/01 10:24:14 goose: up to current file version: 313592026/10/01 10:24:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013602026/10/01 10:24:14 INFO Vacuumed table table=pending_closures13612026/10/01 10:24:14 INFO Vacuumed table table=pending_objects13622026/10/01 10:24:14 INFO Vacuumed table table=multipart_uploads13632026/10/01 10:24:14 INFO Vacuumed table table=closures13642026/10/01 10:24:14 INFO Vacuumed table table=objects1365--- PASS: TestGCSweepDeliversEachKeyOnce (0.68s)1366=== CONT TestReadRedirectKeepsNarinfoProxied13672026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=013682026/10/01 10:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period13692026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures13702026/10/01 10:24:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013712026/10/01 10:24:14 INFO Vacuumed table table=pending_closures13722026/10/01 10:24:14 INFO Vacuumed table table=pending_objects13732026/10/01 10:24:14 INFO Vacuumed table table=multipart_uploads13742026/10/01 10:24:14 INFO Vacuumed table table=closures13752026/10/01 10:24:14 INFO Vacuumed table table=objects1376--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.72s)1377=== CONT TestReadRedirectNar13782026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=013792026/10/01 10:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period13802026/10/01 10:24:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1381--- PASS: TestService_Rustfstest (0.66s)1382=== CONT TestReadProxyDisabled13832026/10/01 10:24:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=013842026/10/01 10:24:14 INFO Vacuumed table table=pending_closures13852026/10/01 10:24:14 INFO Vacuumed table table=pending_objects13862026/10/01 10:24:14 INFO Vacuumed table table=multipart_uploads13872026/10/01 10:24:14 INFO Vacuumed table table=closures13882026/10/01 10:24:14 INFO Vacuumed table table=objects1389--- PASS: TestSweepSkipsRowsLockedByPush (0.74s)1390=== CONT TestReadProxyRootRedirectsToIndexHTML13912026-10-01 10:24:14.277 UTC [714] ERROR: relation "goose_db_version" does not exist at character 3613922026-10-01 10:24:14.277 UTC [714] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13932026/10/01 10:24:14 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLjg5MzdjNjRiLTExMGMtNDRlNy05MTY0LTUzZTFmNzJjZTNkOHgxNzkwODUwMjUzODE1NDc4Nzgy parts=1013942026/10/01 10:24:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13952026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.36ms)13962026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)13972026/10/01 10:24:14 INFO Completed upload id=113982026/10/01 10:24:14 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013992026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.75ms)14002026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures1401--- PASS: TestReadProxyInvalidPath (0.76s)1402=== CONT TestReadProxyConditionalGet14032026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)14042026/10/01 10:24:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures1405--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.78s)1406=== CONT TestReadProxyOutlastsServerWriteTimeout14072026/10/01 10:24:14 OK 20260905000000_add_claims.sql (13.86ms)14082026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=014092026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.64ms)14102026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.41ms)14112026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000014122026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.53ms)14132026-10-01 10:24:14.324 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3614142026-10-01 10:24:14.324 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/10/01 10:24:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014162026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.7ms)14172026/10/01 10:24:14 OK 3_commit_push.sql (1.46ms)14182026/10/01 10:24:14 goose: up to current file version: 314192026/10/01 10:24:14 INFO Vacuumed table table=pending_closures14202026/10/01 10:24:14 INFO Vacuumed table table=pending_objects14212026/10/01 10:24:14 INFO Vacuumed table table=multipart_uploads14222026/10/01 10:24:14 INFO Vacuumed table table=closures14232026/10/01 10:24:14 OK 20241026095416_initial_model.sql (11.91ms)14242026/10/01 10:24:14 INFO Vacuumed table table=objects14252026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)14262026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=014272026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.57ms)14282026/10/01 10:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period14292026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)14302026/10/01 10:24:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001431--- PASS: TestService_createPendingClosureHandler (1.00s)1432=== CONT TestReadProxyHead14332026/10/01 10:24:14 OK 20260905000000_add_claims.sql (2.96ms)14342026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures14352026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.27ms)14362026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.14ms)14372026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000014382026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.03ms)14392026-10-01 10:24:14.365 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3614402026-10-01 10:24:14.365 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14412026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.56ms)14422026/10/01 10:24:14 OK 3_commit_push.sql (1.14ms)14432026/10/01 10:24:14 goose: up to current file version: 314442026/10/01 10:24:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014452026/10/01 10:24:14 INFO Vacuumed table table=pending_closures14462026-10-01 10:24:14.376 UTC [744] ERROR: relation "goose_db_version" does not exist at character 3614472026-10-01 10:24:14.376 UTC [744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/10/01 10:24:14 INFO Vacuumed table table=pending_objects14492026/10/01 10:24:14 INFO Vacuumed table table=multipart_uploads14502026/10/01 10:24:14 INFO Vacuumed table table=closures14512026/10/01 10:24:14 INFO Vacuumed table table=objects14522026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.93ms)1453--- PASS: TestSweepRechecksPendingAfterLocking (0.85s)1454=== CONT TestCreatePin_ReservedPins14552026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures14562026-10-01 10:24:14.387 UTC [745] ERROR: relation "goose_db_version" does not exist at character 3614572026-10-01 10:24:14.387 UTC [745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14582026/10/01 10:24:14 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14592026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures14602026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (12.39ms)14612026/10/01 10:24:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14622026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.3ms)1463--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.78s)1464=== CONT TestReadProxy40414652026/10/01 10:24:14 OK 20241026095416_initial_model.sql (12.43ms)14662026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (7.45ms)14672026/10/01 10:24:14 OK 20241026095416_initial_model.sql (10.53ms)14682026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)14692026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)14702026/10/01 10:24:14 OK 20260905000000_add_claims.sql (2.63ms)14712026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.17ms)14722026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.2ms)14732026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.37ms)14742026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.75ms)14752026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000014762026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)14772026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)14782026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.09ms)14792026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.37ms)14802026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.7ms)14812026-10-01 10:24:14.416 UTC [748] ERROR: relation "goose_db_version" does not exist at character 3614822026-10-01 10:24:14.416 UTC [748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14832026/10/01 10:24:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLmJhYzI3YjYzLWNmM2EtNGQ3MS1iYmU1LTg0ZjA1NjhhNTFjYXgxNzkwODUwMjUzOTQzMDE0MDA5 parts=1014842026/10/01 10:24:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14852026/10/01 10:24:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36549/oidc14862026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.3ms)14872026/10/01 10:24:14 OK 3_commit_push.sql (1.97ms)14882026/10/01 10:24:14 goose: up to current file version: 314892026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.13ms)14902026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.65ms)14912026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000014922026/10/01 10:24:14 INFO Completed upload id=114932026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (4.15ms)14942026-10-01 10:24:14.423 UTC [749] ERROR: relation "goose_db_version" does not exist at character 3614952026-10-01 10:24:14.423 UTC [749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14962026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.58ms)14972026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures14982026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.33ms)14992026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000015002026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.61ms)15012026/10/01 10:24:14 OK 3_commit_push.sql (1.73ms)15022026/10/01 10:24:14 goose: up to current file version: 315032026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.61ms)15042026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures15052026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.02ms)15062026/10/01 10:24:14 OK 3_commit_push.sql (2.23ms)15072026/10/01 10:24:14 goose: up to current file version: 315082026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.73ms)15092026/10/01 10:24:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15102026/10/01 10:24:14 WARN Found objects in DB but missing from S3, will re-upload count=115112026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)1512--- PASS: TestService_verifyS3Integrity (1.08s)1513=== CONT TestReadProxyNarStreaming15142026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.31ms)15152026/10/01 10:24:14 OK 20241026095416_initial_model.sql (10.66ms)15162026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)1517--- PASS: TestGetExistingObjectsLocksRows (0.91s)15182026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)1519=== CONT TestReadProxyNarinfoAlreadyDecompressed15202026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.74ms)15212026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.09ms)15222026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.1ms)15232026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)15242026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.28ms)15252026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000015262026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures15272026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.27ms)15282026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.31ms)15292026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (3.13ms)15302026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.1ms)15312026/10/01 10:24:14 OK 3_commit_push.sql (1.49ms)15322026/10/01 10:24:14 goose: up to current file version: 315332026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.79ms)15342026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000015352026-10-01 10:24:14.461 UTC [757] ERROR: relation "goose_db_version" does not exist at character 3615362026-10-01 10:24:14.461 UTC [757] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15372026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.46ms)15382026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.55ms)15392026/10/01 10:24:14 OK 3_commit_push.sql (1.28ms)15402026/10/01 10:24:14 goose: up to current file version: 315412026/10/01 10:24:14 OK 20241026095416_initial_model.sql (10.65ms)15422026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=015432026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (3.45ms)15442026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures15452026/10/01 10:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period15462026/10/01 10:24:14 OK 20251218171726_add_pins.sql (11.36ms)15472026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)15482026/10/01 10:24:14 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15492026/10/01 10:24:14 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."15502026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.08ms)1551--- PASS: TestFailedS3DeleteKeepsTombstone (0.97s)1552=== CONT TestReadProxyNarinfo15532026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.93ms)15542026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (3.34ms)15552026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000015562026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures15572026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.56ms)15582026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.98ms)15592026/10/01 10:24:14 OK 3_commit_push.sql (1.84ms)15602026/10/01 10:24:14 goose: up to current file version: 315612026-10-01 10:24:14.516 UTC [761] ERROR: relation "goose_db_version" does not exist at character 3615622026-10-01 10:24:14.516 UTC [761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15632026/10/01 10:24:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15642026/10/01 10:24:14 INFO Received uploads request method=POST path=/api/pending_closures15652026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.5ms)15662026/10/01 10:24:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLmNkNDU0MmMzLTM2MDItNDViMC1iNDI5LTViZjgwN2IyYWY4OXgxNzkwODUwMjU0NTAyNzI0MTAw15672026-10-01 10:24:14.533 UTC [762] ERROR: relation "goose_db_version" does not exist at character 3615682026-10-01 10:24:14.533 UTC [762] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15692026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)15702026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.02ms)15712026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)1572=== RUN TestPush_RejectsBadRequests/no_roots15732026/10/01 10:24:14 OK 20260905000000_add_claims.sql (2.78ms)1574=== PAUSE TestPush_RejectsBadRequests/no_roots1575=== RUN TestPush_RejectsBadRequests/no_objects1576=== PAUSE TestPush_RejectsBadRequests/no_objects1577=== RUN TestPush_RejectsBadRequests/bad_root1578=== PAUSE TestPush_RejectsBadRequests/bad_root1579=== RUN TestPush_RejectsBadRequests/root_not_in_objects1580=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1581=== CONT TestIsValidCachePath1582=== RUN TestIsValidCachePath/narinfo1583=== PAUSE TestIsValidCachePath/narinfo1584=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1585=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1586=== RUN TestIsValidCachePath/nar_zst1587=== PAUSE TestIsValidCachePath/nar_zst1588=== RUN TestIsValidCachePath/nar_xz1589=== PAUSE TestIsValidCachePath/nar_xz1590=== RUN TestIsValidCachePath/nar_bz21591=== PAUSE TestIsValidCachePath/nar_bz21592=== RUN TestIsValidCachePath/nar_uncompressed1593=== PAUSE TestIsValidCachePath/nar_uncompressed1594=== RUN TestIsValidCachePath/ls15952026/10/01 10:24:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLmNkNDU0MmMzLTM2MDItNDViMC1iNDI5LTViZjgwN2IyYWY4OXgxNzkwODUwMjU0NTAyNzI0MTAw parts=11596=== PAUSE TestIsValidCachePath/ls1597=== RUN TestIsValidCachePath/log1598=== PAUSE TestIsValidCachePath/log1599=== RUN TestIsValidCachePath/realisation1600=== PAUSE TestIsValidCachePath/realisation1601=== RUN TestIsValidCachePath/nix-cache-info1602=== PAUSE TestIsValidCachePath/nix-cache-info1603=== RUN TestIsValidCachePath/index.html1604=== PAUSE TestIsValidCachePath/index.html1605=== RUN TestIsValidCachePath/traversal_parent16062026-10-01 10:24:14.546 UTC [763] ERROR: relation "goose_db_version" does not exist at character 3616072026-10-01 10:24:14.546 UTC [763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1608=== PAUSE TestIsValidCachePath/traversal_parent1609=== RUN TestIsValidCachePath/traversal_in_middle1610=== PAUSE TestIsValidCachePath/traversal_in_middle16112026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.28ms)1612=== RUN TestIsValidCachePath/invalid_char_e1613=== PAUSE TestIsValidCachePath/invalid_char_e1614=== RUN TestIsValidCachePath/invalid_char_u1615=== PAUSE TestIsValidCachePath/invalid_char_u1616=== RUN TestIsValidCachePath/random_path1617=== PAUSE TestIsValidCachePath/random_path1618=== RUN TestIsValidCachePath/empty1619=== PAUSE TestIsValidCachePath/empty1620=== RUN TestIsValidCachePath/leading_slash1621=== PAUSE TestIsValidCachePath/leading_slash1622=== RUN TestIsValidCachePath/wrong_extension1623=== PAUSE TestIsValidCachePath/wrong_extension1624=== RUN TestIsValidCachePath/short_hash1625=== PAUSE TestIsValidCachePath/short_hash1626=== CONT TestProxyHeadersOnlyTrustedOnSocket1627--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.70s)1628=== CONT TestPresentReportsOnlyClosureRoots16292026/10/01 10:24:14 OK 20241026095416_initial_model.sql (8.05ms)16302026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (3.01ms)16312026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000016322026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)16332026-10-01 10:24:14.552 UTC [764] ERROR: relation "goose_db_version" does not exist at character 3616342026-10-01 10:24:14.552 UTC [764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16352026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.18ms)16362026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.68ms)16372026/10/01 10:24:14 OK 2_object_stats_trigger.sql (814.17µs)16382026/10/01 10:24:14 OK 3_commit_push.sql (978.31µs)16392026/10/01 10:24:14 goose: up to current file version: 316402026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)16412026/10/01 10:24:14 OK 20241026095416_initial_model.sql (8.45ms)16422026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.33ms)16432026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)16442026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.33ms)16452026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.07ms)16462026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.52ms)16472026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000016482026/10/01 10:24:14 OK 20241026095416_initial_model.sql (10.03ms)16492026/10/01 10:24:14 OK 1_commit_pending_closure.sql (1.85ms)16502026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)16512026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)16522026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.96ms)16532026/10/01 10:24:14 OK 3_commit_push.sql (1.68ms)16542026/10/01 10:24:14 goose: up to current file version: 316552026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.96ms)16562026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.07ms)16572026/10/01 10:24:14 INFO Received push request method=POST path=/api/pushes16582026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (1.95ms)16592026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)16602026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.26ms)16612026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000016622026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.11ms)16632026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.27ms)16642026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.62ms)16652026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.87ms)16662026/10/01 10:24:14 OK 3_commit_push.sql (1.17ms)16672026/10/01 10:24:14 goose: up to current file version: 316682026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (10.38ms)16692026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000016702026/10/01 10:24:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16712026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.34ms)16722026/10/01 10:24:14 INFO Signed narinfos id=1 count=11673--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.71s)1674=== CONT TestPresentNotReportedWhileGCDeletesClosure16752026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.2ms)16762026/10/01 10:24:14 OK 3_commit_push.sql (682.21µs)16772026/10/01 10:24:14 goose: up to current file version: 316782026/10/01 10:24:14 INFO Received push request method=POST path=/api/pushes16792026-10-01 10:24:14.608 UTC [770] ERROR: relation "goose_db_version" does not exist at character 3616802026-10-01 10:24:14.608 UTC [770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16812026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.46ms)16822026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)16832026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.25ms)16842026/10/01 10:24:14 INFO Received complete push request method=POST path=/api/pushes/1/complete16852026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)16862026/10/01 10:24:14 INFO Received push request method=POST path=/api/pushes16872026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.04ms)16882026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.23ms)16892026/10/01 10:24:14 INFO Received push request method=POST path=/api/pushes16902026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.89ms)16912026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000016922026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.51ms)16932026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.49ms)16942026/10/01 10:24:14 OK 3_commit_push.sql (1.23ms)16952026/10/01 10:24:14 goose: up to current file version: 316962026-10-01 10:24:14.655 UTC [773] ERROR: relation "goose_db_version" does not exist at character 3616972026-10-01 10:24:14.655 UTC [773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16982026-10-01 10:24:14.655 UTC [774] ERROR: relation "goose_db_version" does not exist at character 3616992026-10-01 10:24:14.655 UTC [774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17002026/10/01 10:24:14 INFO Received complete push request method=POST path=/api/pushes/1/complete17012026/10/01 10:24:14 INFO Received push request method=POST path=/api/pushes1702--- PASS: TestPush_CompleteCommitsEveryRoot (0.67s)1703=== CONT TestParseSingleRange17042026/10/01 10:24:14 OK 20241026095416_initial_model.sql (8.57ms)1705=== RUN TestParseSingleRange/none1706=== PAUSE TestParseSingleRange/none1707=== RUN TestParseSingleRange/unknown_unit1708=== PAUSE TestParseSingleRange/unknown_unit1709=== RUN TestParseSingleRange/multi-range_ignored1710=== PAUSE TestParseSingleRange/multi-range_ignored1711=== RUN TestParseSingleRange/malformed_no_dash1712=== PAUSE TestParseSingleRange/malformed_no_dash1713=== RUN TestParseSingleRange/malformed_both_empty1714=== PAUSE TestParseSingleRange/malformed_both_empty1715=== RUN TestParseSingleRange/malformed_end_before_start1716=== PAUSE TestParseSingleRange/malformed_end_before_start1717=== RUN TestParseSingleRange/closed1718=== PAUSE TestParseSingleRange/closed1719=== RUN TestParseSingleRange/open-ended1720=== PAUSE TestParseSingleRange/open-ended1721=== RUN TestParseSingleRange/end_clamped_to_size1722=== PAUSE TestParseSingleRange/end_clamped_to_size1723=== RUN TestParseSingleRange/suffix1724=== PAUSE TestParseSingleRange/suffix17252026/10/01 10:24:14 OK 20241026095416_initial_model.sql (8.72ms)1726=== RUN TestParseSingleRange/suffix_exceeds_size1727=== PAUSE TestParseSingleRange/suffix_exceeds_size1728=== RUN TestParseSingleRange/single_byte1729=== PAUSE TestParseSingleRange/single_byte1730=== RUN TestParseSingleRange/start_past_EOF1731=== PAUSE TestParseSingleRange/start_past_EOF1732=== RUN TestParseSingleRange/start_far_past_EOF1733=== PAUSE TestParseSingleRange/start_far_past_EOF1734=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded17352026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)17362026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)17372026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.6ms)17382026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.03ms)17392026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)17402026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.37ms)17412026/10/01 10:24:14 OK 20260905000000_add_claims.sql (2.13ms)17422026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (1.49ms)17432026/10/01 10:24:14 OK 20260905000000_add_claims.sql (2.18ms)17442026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.24ms)17452026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000017462026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (1.65ms)17472026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2ms)17482026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.23ms)17492026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000017502026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.29ms)17512026/10/01 10:24:14 OK 3_commit_push.sql (686.93µs)17522026/10/01 10:24:14 goose: up to current file version: 317532026/10/01 10:24:14 OK 1_commit_pending_closure.sql (1.69ms)17542026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.73ms)17552026-10-01 10:24:14.690 UTC [782] ERROR: relation "goose_db_version" does not exist at character 3617562026-10-01 10:24:14.690 UTC [782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17572026/10/01 10:24:14 OK 3_commit_push.sql (1.58ms)17582026/10/01 10:24:14 goose: up to current file version: 31759--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.68s)1760=== CONT TestOrphanedObjectsGCStressTest1761--- PASS: TestPushWaitsForSweepHoldingRow (1.16s)1762=== CONT TestOrphanedObjectsGC17632026/10/01 10:24:14 INFO Aborted multipart uploads count=0 kept=017642026/10/01 10:24:14 OK 20241026095416_initial_model.sql (8.4ms)17652026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)17662026/10/01 10:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period17672026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.73ms)17682026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)1769--- PASS: TestReadRedirectUsesPublicS3URL (0.64s)1770=== CONT TestService_NativeMTLS17712026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.38ms)17722026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.41ms)17732026/10/01 10:24:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=017742026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (3.14ms)17752026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000017762026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.81ms)17772026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.83ms)17782026/10/01 10:24:14 INFO Vacuumed table table=pending_closures17792026/10/01 10:24:14 OK 3_commit_push.sql (10.05ms)17802026/10/01 10:24:14 goose: up to current file version: 31781--- PASS: TestReadProxyRangeRequest (0.54s)1782=== CONT TestObjectStatsTrigger17832026/10/01 10:24:14 INFO Vacuumed table table=pending_objects17842026/10/01 10:24:14 INFO Vacuumed table table=multipart_uploads17852026/10/01 10:24:14 INFO Vacuumed table table=closures17862026/10/01 10:24:14 INFO Vacuumed table table=objects17872026/10/01 10:24:14 INFO Received complete push request method=POST path=/api/pushes/2/complete1788--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.79s)1789=== CONT TestMultipartCleanup1790--- PASS: TestReadRedirectKeepsNarinfoProxied (0.55s)1791=== CONT TestPendingCleanupUsesOneCutoff17922026-10-01 10:24:14.772 UTC [793] ERROR: relation "goose_db_version" does not exist at character 3617932026-10-01 10:24:14.772 UTC [793] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17942026/10/01 10:24:14 OK 20241026095416_initial_model.sql (10.81ms)1795--- PASS: TestReadRedirectNar (0.54s)1796=== CONT TestServerTLSConfig1797=== RUN TestServerTLSConfig/no_client_CA1798=== PAUSE TestServerTLSConfig/no_client_CA1799=== RUN TestServerTLSConfig/missing_CA_file1800=== PAUSE TestServerTLSConfig/missing_CA_file1801=== RUN TestServerTLSConfig/not_a_PEM_file1802=== PAUSE TestServerTLSConfig/not_a_PEM_file1803=== CONT TestClientWithDependencies18042026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)18052026-10-01 10:24:14.799 UTC [796] ERROR: relation "goose_db_version" does not exist at character 3618062026-10-01 10:24:14.799 UTC [796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18072026/10/01 10:24:14 OK 20251218171726_add_pins.sql (11.73ms)18082026-10-01 10:24:14.808 UTC [799] ERROR: relation "goose_db_version" does not exist at character 3618092026-10-01 10:24:14.808 UTC [799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18102026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)1811--- PASS: TestReadProxyDisabled (0.55s)1812=== CONT TestCacheConfigHandler1813=== RUN TestCacheConfigHandler/full_config,_no_issuer1814=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1815=== RUN TestCacheConfigHandler/no_cache_url_configured1816=== PAUSE TestCacheConfigHandler/no_cache_url_configured1817=== RUN TestCacheConfigHandler/no_signing_keys1818=== PAUSE TestCacheConfigHandler/no_signing_keys1819=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1820=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1821=== CONT TestDeduplicatedObjectsRecordedAsPending18222026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.9ms)18232026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.7ms)18242026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.94ms)18252026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000018262026/10/01 10:24:14 OK 20241026095416_initial_model.sql (12.26ms)18272026/10/01 10:24:14 OK 20241026095416_initial_model.sql (10.72ms)18282026-10-01 10:24:14.824 UTC [801] ERROR: relation "goose_db_version" does not exist at character 3618292026-10-01 10:24:14.824 UTC [801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18302026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.65ms)18312026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)18322026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)18332026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.06ms)18342026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.07ms)18352026/10/01 10:24:14 OK 3_commit_push.sql (2.3ms)18362026/10/01 10:24:14 goose: up to current file version: 318372026/10/01 10:24:14 OK 20251218171726_add_pins.sql (4.49ms)18382026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)18392026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)18402026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.01ms)18412026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.68ms)18422026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.14ms)18432026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.83ms)18442026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.56ms)18452026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000018462026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.69ms)18472026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)18482026-10-01 10:24:14.845 UTC [803] ERROR: relation "goose_db_version" does not exist at character 3618492026-10-01 10:24:14.845 UTC [803] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18502026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.31ms)18512026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.97ms)18522026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000018532026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.89ms)18542026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.6ms)18552026/10/01 10:24:14 OK 3_commit_push.sql (1.63ms)18562026/10/01 10:24:14 goose: up to current file version: 318572026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.57ms)1858--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.58s)1859=== CONT TestClientMultipleUploads18602026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)18612026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.25ms)18622026/10/01 10:24:14 OK 3_commit_push.sql (1.38ms)18632026/10/01 10:24:14 goose: up to current file version: 318642026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.46ms)18652026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.24ms)18662026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.02ms)18672026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000018682026/10/01 10:24:14 OK 20241026095416_initial_model.sql (8.69ms)18692026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.73ms)18702026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)18712026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.81ms)18722026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.65ms)18732026-10-01 10:24:14.866 UTC [806] ERROR: relation "goose_db_version" does not exist at character 3618742026-10-01 10:24:14.866 UTC [806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18752026/10/01 10:24:14 OK 3_commit_push.sql (1.75ms)18762026/10/01 10:24:14 goose: up to current file version: 318772026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)18782026-10-01 10:24:14.871 UTC [807] ERROR: relation "goose_db_version" does not exist at character 3618792026-10-01 10:24:14.871 UTC [807] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18802026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.01ms)18812026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (10.25ms)18822026/10/01 10:24:14 OK 20241026095416_initial_model.sql (13.79ms)1883--- PASS: TestReadProxyConditionalGet (0.59s)1884=== CONT TestPushDedupSurvivesConcurrentGC18852026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (4.28ms)18862026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000018872026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)18882026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.44ms)18892026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.82ms)18902026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.41ms)18912026/10/01 10:24:14 OK 3_commit_push.sql (1.44ms)18922026/10/01 10:24:14 goose: up to current file version: 318932026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)18942026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.97ms)18952026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)18962026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.48ms)18972026/10/01 10:24:14 OK 20251218171726_add_pins.sql (3.24ms)18982026-10-01 10:24:14.904 UTC [810] ERROR: relation "goose_db_version" does not exist at character 3618992026-10-01 10:24:14.904 UTC [810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19002026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.91ms)19012026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.72ms)19022026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000019032026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (5.62ms)19042026/10/01 10:24:14 OK 1_commit_pending_closure.sql (3.25ms)19052026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.81ms)19062026/10/01 10:24:14 OK 20260905000000_add_claims.sql (4.74ms)19072026/10/01 10:24:14 OK 3_commit_push.sql (2.17ms)19082026/10/01 10:24:14 goose: up to current file version: 319092026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (3.21ms)19102026-10-01 10:24:14.917 UTC [811] ERROR: relation "goose_db_version" does not exist at character 3619112026-10-01 10:24:14.917 UTC [811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19122026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.37ms)19132026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (4.07ms)19142026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000019152026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)19162026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.74ms)19172026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.72ms)19182026/10/01 10:24:14 OK 2_object_stats_trigger.sql (2.22ms)19192026/10/01 10:24:14 OK 3_commit_push.sql (1.56ms)19202026/10/01 10:24:14 goose: up to current file version: 319212026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)19222026/10/01 10:24:14 OK 20241026095416_initial_model.sql (8.01ms)19232026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.17ms)19242026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (2ms)19252026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.32ms)19262026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.59ms)19272026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (2.12ms)19282026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000019292026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.03ms)19302026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.64ms)19312026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.26ms)19322026/10/01 10:24:14 OK 20260905000000_add_claims.sql (3.29ms)19332026/10/01 10:24:14 OK 3_commit_push.sql (2.08ms)19342026/10/01 10:24:14 goose: up to current file version: 319352026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (2.27ms)19362026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.89ms)19372026/10/01 10:24:14 goose: successfully migrated database to version: 202609231200001938--- PASS: TestReadProxyHead (0.59s)1939=== CONT TestGCMetrics19402026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.2ms)19412026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.41ms)19422026/10/01 10:24:14 OK 3_commit_push.sql (1.39ms)19432026/10/01 10:24:14 goose: up to current file version: 319442026-10-01 10:24:14.955 UTC [813] ERROR: relation "goose_db_version" does not exist at character 3619452026-10-01 10:24:14.955 UTC [813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19462026/10/01 10:24:14 OK 20241026095416_initial_model.sql (9.32ms)19472026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)19482026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.75ms)19492026/10/01 10:24:14 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)19502026-10-01 10:24:14.980 UTC [815] ERROR: relation "goose_db_version" does not exist at character 3619512026-10-01 10:24:14.980 UTC [815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19522026/10/01 10:24:14 OK 20260905000000_add_claims.sql (2.75ms)19532026/10/01 10:24:14 OK 20260920000000_drop_claims.sql (1.98ms)19542026/10/01 10:24:14 OK 20260923120000_add_pushes.sql (1.32ms)19552026/10/01 10:24:14 goose: successfully migrated database to version: 2026092312000019562026/10/01 10:24:14 OK 1_commit_pending_closure.sql (2.38ms)19572026/10/01 10:24:14 OK 2_object_stats_trigger.sql (1.35ms)19582026/10/01 10:24:14 OK 3_commit_push.sql (1.02ms)19592026/10/01 10:24:14 goose: up to current file version: 31960--- PASS: TestReadProxy404 (0.59s)1961=== CONT TestClientIntegration19622026/10/01 10:24:14 OK 20241026095416_initial_model.sql (7.77ms)19632026/10/01 10:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)19642026/10/01 10:24:14 OK 20251218171726_add_pins.sql (2.62ms)19652026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)19662026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.78ms)19672026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.02ms)19682026/10/01 10:24:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19692026/10/01 10:24:15 WARN Refused reserved pin name=worker-x86_64-linux19702026/10/01 10:24:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19712026/10/01 10:24:15 INFO Received create pin request method=POST path=/api/pins/my-app19722026/10/01 10:24:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19732026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.05ms)19742026/10/01 10:24:15 goose: successfully migrated database to version: 202609231200001975--- PASS: TestCreatePin_ReservedPins (0.63s)1976=== CONT TestGCBugBareHashReferences19772026/10/01 10:24:15 OK 1_commit_pending_closure.sql (9.66ms)19782026/10/01 10:24:15 OK 2_object_stats_trigger.sql (3.71ms)19792026/10/01 10:24:15 OK 3_commit_push.sql (1.51ms)19802026/10/01 10:24:15 goose: up to current file version: 31981--- PASS: TestReadProxyNarStreaming (0.60s)1982=== CONT TestClientErrorHandling19832026-10-01 10:24:15.036 UTC [820] ERROR: relation "goose_db_version" does not exist at character 3619842026-10-01 10:24:15.036 UTC [820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1985=== RUN TestClientErrorHandling/InvalidStorePath1986=== PAUSE TestClientErrorHandling/InvalidStorePath1987=== RUN TestClientErrorHandling/InvalidAuthToken1988=== PAUSE TestClientErrorHandling/InvalidAuthToken1989=== RUN TestClientErrorHandling/ServerNotAvailable1990=== PAUSE TestClientErrorHandling/ServerNotAvailable1991=== CONT TestLeadEndsOnShutdown19922026/10/01 10:24:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19932026/10/01 10:24:15 OK 20241026095416_initial_model.sql (9.51ms)19942026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)19952026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.7ms)19962026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)1997--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.62s)1998=== CONT TestClientCADerivations19992026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.5ms)20002026/10/01 10:24:15 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLmM0YjU0YzlmLWYyNDctNDJiNS04NTlkLWJhMTRmMzEyZGIxMXgxNzkwODUwMjU0NDcxNDQ4Mjk0 parts=1220012026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (3.32ms)20022026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures20032026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.34ms)20042026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000020052026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.72ms)2006--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.32s)20072026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.61ms)2008=== CONT TestLeadElectsOneAndHandsOver20092026/10/01 10:24:15 OK 3_commit_push.sql (1.44ms)20102026/10/01 10:24:15 goose: up to current file version: 320112026-10-01 10:24:15.094 UTC [827] ERROR: relation "goose_db_version" does not exist at character 3620122026-10-01 10:24:15.094 UTC [827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20132026/10/01 10:24:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20142026-10-01 10:24:15.108 UTC [828] ERROR: relation "goose_db_version" does not exist at character 3620152026-10-01 10:24:15.108 UTC [828] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20162026/10/01 10:24:15 OK 20241026095416_initial_model.sql (9.42ms)20172026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)20182026/10/01 10:24:15 OK 20251218171726_add_pins.sql (11.02ms)20192026/10/01 10:24:15 OK 20241026095416_initial_model.sql (12.37ms)20202026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)20212026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)20222026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.87ms)20232026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.03ms)2024--- PASS: TestPresentReportsOnlyClosureRoots (0.59s)2025=== CONT TestCacheStatsHandler20262026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (3.14ms)20272026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)20282026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.33ms)20292026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000020302026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.86ms)20312026/10/01 10:24:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLjA2M2NjMDIxLWJiZDItNDIzYS05NDE4LWE1YzdiODA1ZWJiMHgxNzkwODUwMjU0NTI0NTY5Mzg4 parts=1220322026/10/01 10:24:15 OK 1_commit_pending_closure.sql (3.14ms)20332026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures20342026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.93ms)20352026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.65ms)20362026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.38ms)20372026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000020382026/10/01 10:24:15 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"20392026/10/01 10:24:15 OK 3_commit_push.sql (2.2ms)20402026/10/01 10:24:15 goose: up to current file version: 320412026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.31ms)20422026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.27ms)20432026/10/01 10:24:15 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2861234245/001/proxy.sock20442026-10-01 10:24:15.149 UTC [830] ERROR: relation "goose_db_version" does not exist at character 3620452026-10-01 10:24:15.149 UTC [830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20462026/10/01 10:24:15 INFO Starting HTTP server address=127.0.0.1:4599920472026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures20482026/10/01 10:24:15 OK 3_commit_push.sql (2.07ms)20492026/10/01 10:24:15 goose: up to current file version: 320502026/10/01 10:24:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"20512026/10/01 10:24:15 INFO Shutdown signal received, draining in-flight requests timeout=10s2052--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.60s)2053=== CONT TestResolveDBConnectionString2054=== RUN TestResolveDBConnectionString/flag_wins2055=== PAUSE TestResolveDBConnectionString/flag_wins2056=== RUN TestResolveDBConnectionString/file_when_flag_empty2057=== PAUSE TestResolveDBConnectionString/file_when_flag_empty2058=== RUN TestResolveDBConnectionString/missing_file_is_an_error2059=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error2060=== RUN TestResolveDBConnectionString/PGHOST_allows_empty2061=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty2062=== RUN TestResolveDBConnectionString/nothing_configured2063=== PAUSE TestResolveDBConnectionString/nothing_configured2064=== CONT TestClientSharedPathCommittedMidPush20652026/10/01 10:24:15 OK 20241026095416_initial_model.sql (8.22ms)20662026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)20672026-10-01 10:24:15.169 UTC [834] ERROR: relation "goose_db_version" does not exist at character 3620682026-10-01 10:24:15.169 UTC [834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20692026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.17ms)20702026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)20712026-10-01 10:24:15.174 UTC [835] ERROR: relation "goose_db_version" does not exist at character 3620722026-10-01 10:24:15.174 UTC [835] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20732026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.22ms)20742026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (10.95ms)20752026/10/01 10:24:15 OK 20241026095416_initial_model.sql (12.66ms)20762026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)20772026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (3.25ms)20782026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000020792026/10/01 10:24:15 OK 1_commit_pending_closure.sql (3.33ms)20802026/10/01 10:24:15 OK 20251218171726_add_pins.sql (4.39ms)20812026/10/01 10:24:15 OK 20241026095416_initial_model.sql (9.07ms)20822026/10/01 10:24:15 OK 2_object_stats_trigger.sql (2.11ms)20832026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)20842026/10/01 10:24:15 OK 3_commit_push.sql (1.56ms)20852026/10/01 10:24:15 goose: up to current file version: 320862026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)20872026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.66ms)20882026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.22ms)20892026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.26ms)20902026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)20912026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.01ms)20922026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000020932026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.14ms)20942026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.17ms)20952026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.2ms)20962026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.44ms)20972026/10/01 10:24:15 OK 3_commit_push.sql (1.05ms)20982026/10/01 10:24:15 goose: up to current file version: 320992026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.29ms)21002026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000021012026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.25ms)21022026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.54ms)21032026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures21042026/10/01 10:24:15 OK 3_commit_push.sql (1.54ms)21052026/10/01 10:24:15 goose: up to current file version: 321062026-10-01 10:24:15.239 UTC [837] ERROR: relation "goose_db_version" does not exist at character 3621072026-10-01 10:24:15.239 UTC [837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2108--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.57s)2109=== CONT TestClientPushesUseOnePush21102026/10/01 10:24:15 OK 20241026095416_initial_model.sql (6.76ms)21112026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)21122026-10-01 10:24:15.253 UTC [840] ERROR: relation "goose_db_version" does not exist at character 3621132026-10-01 10:24:15.253 UTC [840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21142026/10/01 10:24:15 OK 20251218171726_add_pins.sql (11.3ms)21152026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)21162026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.96ms)21172026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.16ms)21182026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.14ms)21192026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000021202026/10/01 10:24:15 OK 20241026095416_initial_model.sql (8.82ms)21212026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)21222026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.18ms)21232026/10/01 10:24:15 OK 2_object_stats_trigger.sql (826.48µs)21242026/10/01 10:24:15 OK 3_commit_push.sql (727.2µs)21252026/10/01 10:24:15 goose: up to current file version: 321262026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.29ms)21272026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)21282026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.41ms)21292026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.72ms)21302026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.21ms)21312026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000021322026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.48ms)21332026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.7ms)21342026/10/01 10:24:15 OK 3_commit_push.sql (1.53ms)21352026/10/01 10:24:15 goose: up to current file version: 321362026/10/01 10:24:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"21372026/10/01 10:24:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2138--- PASS: TestService_NativeMTLS (0.59s)2139=== CONT TestService_AuthMiddleware_OIDC21402026-10-01 10:24:15.322 UTC [841] ERROR: relation "goose_db_version" does not exist at character 3621412026-10-01 10:24:15.322 UTC [841] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21422026/10/01 10:24:15 OK 20241026095416_initial_model.sql (7.24ms)21432026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)21442026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.26ms)21452026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (2.98ms)21462026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.03ms)21472026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.12ms)21482026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (1.28ms)21492026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000021502026/10/01 10:24:15 OK 1_commit_pending_closure.sql (1.8ms)21512026/10/01 10:24:15 OK 2_object_stats_trigger.sql (4ms)21522026/10/01 10:24:15 OK 3_commit_push.sql (714.18µs)21532026/10/01 10:24:15 goose: up to current file version: 32154--- PASS: TestObjectStatsTrigger (0.63s)2155=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock21562026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures21572026/10/01 10:24:15 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772162158--- PASS: TestReadProxyNarinfo (0.89s)2159=== CONT TestClientFallsBackToClosures21602026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures21612026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures21622026/10/01 10:24:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38389/oidc21632026/10/01 10:24:15 INFO Received cleanup request method=DELETE path=/api/pending_closures21642026-10-01 10:24:15.449 UTC [849] ERROR: relation "goose_db_version" does not exist at character 3621652026-10-01 10:24:15.449 UTC [849] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21662026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures21672026/10/01 10:24:15 OK 20241026095416_initial_model.sql (12.29ms)21682026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (4.13ms)21692026/10/01 10:24:15 OK 20251218171726_add_pins.sql (8.06ms)2170--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.67s)2171=== CONT TestService_ReadScope_PublicByDefault21722026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)21732026/10/01 10:24:15 INFO Received cleanup request method=DELETE path=/api/pending_closures21742026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.7ms)21752026/10/01 10:24:15 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket57/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""21762026/10/01 10:24:15 INFO Aborted multipart uploads count=0 kept=121772026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.19ms)21782026/10/01 10:24:15 INFO Received cleanup request method=DELETE path=/api/pending_closures21792026/10/01 10:24:15 INFO Aborted multipart uploads count=1 kept=021802026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (9.98ms)21812026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000021822026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.35ms)2183--- PASS: TestMultipartCleanup (0.75s)2184=== CONT TestService_RequireScope_OIDC21852026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.5ms)21862026/10/01 10:24:15 OK 3_commit_push.sql (1.85ms)21872026/10/01 10:24:15 goose: up to current file version: 321882026-10-01 10:24:15.511 UTC [886] ERROR: relation "goose_db_version" does not exist at character 3621892026-10-01 10:24:15.511 UTC [886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21902026/10/01 10:24:15 OK 20241026095416_initial_model.sql (8.87ms)2191=== NAME TestClientWithDependencies2192 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2526836173/001/store/nv0nlmxkbnr4675qb0bnnr1c464qjpz6-test-script21932026-10-01 10:24:15.527 UTC [888] ERROR: relation "goose_db_version" does not exist at character 3621942026-10-01 10:24:15.527 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21952026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)21962026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.58ms)21972026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)21982026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.96ms)21992026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.27ms)2200=== NAME TestClientMultipleUploads2201 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2093387466/001/store/3x85xbk7bvb1597v1mhxbf259mqw22nb-test-file-0.txt22022026/10/01 10:24:15 OK 20241026095416_initial_model.sql (8.06ms)22032026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (1.69ms)22042026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000022052026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)22062026/10/01 10:24:15 OK 1_commit_pending_closure.sql (1.82ms)22072026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.54ms)22082026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.99ms)22092026/10/01 10:24:15 OK 3_commit_push.sql (1.59ms)22102026/10/01 10:24:15 goose: up to current file version: 322112026/10/01 10:24:15 INFO Received uploads request method=POST path=/api/pending_closures22122026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)22132026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.29ms)22142026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.17ms)22152026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.02ms)22162026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000022172026/10/01 10:24:15 INFO Aborted multipart uploads count=0 kept=022182026/10/01 10:24:15 OK 1_commit_pending_closure.sql (1.95ms)2219=== NAME TestClientWithDependencies2220 client_integration_test.go:615: Found 1 dependencies (including self)22212026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.43ms)22222026/10/01 10:24:15 OK 3_commit_push.sql (1.89ms)22232026/10/01 10:24:15 goose: up to current file version: 322242026/10/01 10:24:15 WARN Force mode enabled - objects will be deleted immediately without grace period22252026/10/01 10:24:15 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=022262026/10/01 10:24:15 INFO Vacuumed table table=pending_closures22272026/10/01 10:24:15 INFO Vacuumed table table=pending_objects22282026/10/01 10:24:15 INFO Vacuumed table table=multipart_uploads22292026/10/01 10:24:15 INFO Vacuumed table table=closures22302026/10/01 10:24:15 INFO Vacuumed table table=objects2231=== NAME TestClientMultipleUploads2232 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2093387466/001/store/1cm2rzh9s3spczv3j37vy3jygfiarkis-test-file-1.txt2233--- PASS: TestGCMetrics (0.63s)2234=== CONT TestService_AuthMiddleware_MTLSBoundSubjects22352026-10-01 10:24:15.580 UTC [941] ERROR: relation "goose_db_version" does not exist at character 3622362026-10-01 10:24:15.580 UTC [941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22372026/10/01 10:24:15 OK 20241026095416_initial_model.sql (7.52ms)22382026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)22392026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.66ms)22402026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)22412026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.42ms)2242=== NAME TestClientMultipleUploads2243 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2093387466/001/store/28zs3gpp87cc38c6nfv8rg3wn4pi50v4-test-file-2.txt22442026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (1.94ms)2245=== NAME TestOrphanedObjectsGC2246 orphaned_objects_gc_test.go:290: GC Test Summary:2247 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2248 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2249 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2250 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2251 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2252--- PASS: TestOrphanedObjectsGC (0.91s)2253=== CONT TestService_ReadAuthMiddleware22542026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.12ms)22552026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000022562026/10/01 10:24:15 OK 1_commit_pending_closure.sql (3.04ms)22572026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.38ms)22582026/10/01 10:24:15 OK 3_commit_push.sql (2.18ms)22592026/10/01 10:24:15 goose: up to current file version: 32260=== NAME TestClientIntegration2261 client_integration_test.go:286: Created store path: /build/TestClientIntegration3862171716/002/store/iqrjl13yh6zf6vfpi0dgc14qjx1dy4m0-test-file.txt22622026/10/01 10:24:15 INFO Aborted multipart uploads count=0 kept=022632026/10/01 10:24:15 INFO lead: acquired remote=192.0.2.1:123422642026/10/01 10:24:15 INFO lead: released remote=192.0.2.1:12342265--- PASS: TestLeadEndsOnShutdown (0.59s)2266=== CONT TestService_AuthMiddleware_MTLSProxyHeader22672026/10/01 10:24:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022682026/10/01 10:24:15 INFO Vacuumed table table=pending_closures22692026/10/01 10:24:15 INFO Vacuumed table table=pending_objects22702026/10/01 10:24:15 INFO Vacuumed table table=multipart_uploads22712026/10/01 10:24:15 INFO Vacuumed table table=closures22722026/10/01 10:24:15 INFO Vacuumed table table=objects22732026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes22742026/10/01 10:24:15 INFO Aborted multipart uploads count=0 kept=022752026/10/01 10:24:15 WARN Force mode enabled - objects will be deleted immediately without grace period22762026/10/01 10:24:15 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=022772026/10/01 10:24:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22782026/10/01 10:24:15 INFO Uploading nv0nlmxkbnr4675qb0bnnr1c464qjpz6-test-script (136B)22792026/10/01 10:24:15 INFO Vacuumed table table=pending_closures22802026/10/01 10:24:15 INFO Vacuumed table table=pending_objects22812026/10/01 10:24:15 INFO Vacuumed table table=multipart_uploads22822026/10/01 10:24:15 WARN Failed to register uploaded object key=log/ms21mizrw0y7b1xs3ddw24l8mgq0i6hq-test-script.drv error="server returned 404: 404 page not found\n"22832026/10/01 10:24:15 INFO Vacuumed table table=closures22842026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"22852026/10/01 10:24:15 WARN Failed to register uploaded object key=nv0nlmxkbnr4675qb0bnnr1c464qjpz6.ls error="server returned 404: 404 page not found\n"22862026/10/01 10:24:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22872026/10/01 10:24:15 INFO Signed narinfos id=1 count=122882026/10/01 10:24:15 INFO Uploading 1 narinfos22892026/10/01 10:24:15 INFO Vacuumed table table=objects2290--- PASS: TestPushDedupSurvivesConcurrentGC (0.78s)2291=== CONT TestMetricsInventory22922026/10/01 10:24:15 INFO Received complete push request method=POST path=/api/pushes/1/complete22932026/10/01 10:24:15 WARN Failed to register uploaded object key=nv0nlmxkbnr4675qb0bnnr1c464qjpz6.narinfo error="server returned 404: 404 page not found\n"22942026/10/01 10:24:15 INFO Upload complete. (74ms)22952026-10-01 10:24:15.679 UTC [1067] ERROR: relation "goose_db_version" does not exist at character 3622962026-10-01 10:24:15.679 UTC [1067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2297=== NAME TestClientWithDependencies2298 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2526836173/001/store) requires matching store prefix22992026/10/01 10:24:15 INFO lead: acquired remote=192.0.2.1:123423002026/10/01 10:24:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2301--- PASS: TestClientWithDependencies (0.89s)2302=== CONT TestNARDeduplicationMetadataUploadBug23032026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes23042026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes23052026/10/01 10:24:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2306--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.10s)23072026/10/01 10:24:15 INFO Uploading iqrjl13yh6zf6vfpi0dgc14qjx1dy4m0-test-file.txt (152B)2308=== CONT TestPinProtectsFromGC23092026/10/01 10:24:15 OK 20241026095416_initial_model.sql (9.44ms)23102026/10/01 10:24:15 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLmQyMWFjZmFjLWE0NTMtNDY3ZC05YjI0LWQyYzhkYTNjMTZkYngxNzkwODUwMjU1MTUzNTc1NDY3 error="Get \"http://127.0.0.1:1/bucket29/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"23112026/10/01 10:24:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2VmZDllMTAtMTllZC00MmM0LTlkMTEtMTk5YmQwNTkyZTMyLjkwZDAzMzNlLWI5MjgtNDBjMy05NDU0LWFhODc3Y2M4NjQwN3gxNzkwODUwMjU1MTQ1NTYyNTkw parts=1223122026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)23132026/10/01 10:24:15 INFO Received cleanup request method=DELETE path=/api/pending_closures23142026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"23152026/10/01 10:24:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40209/oidc23162026/10/01 10:24:15 WARN Failed to register uploaded object key=iqrjl13yh6zf6vfpi0dgc14qjx1dy4m0.ls error="server returned 404: 404 page not found\n"23172026/10/01 10:24:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23182026/10/01 10:24:15 INFO Signed narinfos id=1 count=123192026/10/01 10:24:15 INFO Uploading 1 narinfos23202026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.7ms)23212026/10/01 10:24:15 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)23222026/10/01 10:24:15 INFO Uploading 1cm2rzh9s3spczv3j37vy3jygfiarkis-test-file-1.txt (160B)23232026/10/01 10:24:15 INFO Uploading 3x85xbk7bvb1597v1mhxbf259mqw22nb-test-file-0.txt (160B)23242026/10/01 10:24:15 INFO Uploading 28zs3gpp87cc38c6nfv8rg3wn4pi50v4-test-file-2.txt (160B)23252026-10-01 10:24:15.709 UTC [1125] ERROR: relation "goose_db_version" does not exist at character 3623262026-10-01 10:24:15.709 UTC [1125] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23272026/10/01 10:24:15 INFO Aborted multipart uploads count=1 kept=023282026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.23ms)23292026/10/01 10:24:15 INFO Received complete push request method=POST path=/api/pushes/1/complete23302026/10/01 10:24:15 WARN Failed to register uploaded object key=iqrjl13yh6zf6vfpi0dgc14qjx1dy4m0.narinfo error="server returned 404: 404 page not found\n"23312026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"23322026/10/01 10:24:15 WARN Failed to register uploaded object key=3x85xbk7bvb1597v1mhxbf259mqw22nb.ls error="server returned 404: 404 page not found\n"23332026/10/01 10:24:15 WARN Failed to register uploaded object key=1cm2rzh9s3spczv3j37vy3jygfiarkis.ls error="server returned 404: 404 page not found\n"23342026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"23352026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.55ms)23362026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"23372026/10/01 10:24:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23382026/10/01 10:24:15 WARN Failed to register uploaded object key=28zs3gpp87cc38c6nfv8rg3wn4pi50v4.ls error="server returned 404: 404 page not found\n"2339--- PASS: TestRedundantMultipartUpload (1.84s)23402026/10/01 10:24:15 INFO Signed narinfos id=1 count=32341=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23422026/10/01 10:24:15 INFO Received uploads request method=POST path=/23432026/10/01 10:24:15 INFO Uploading 3 narinfos2344=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23452026/10/01 10:24:15 INFO Received request for more parts method=POST path=/2346=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23472026/10/01 10:24:15 INFO Received complete multipart upload request method=POST path=/2348=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23492026/10/01 10:24:15 INFO Received uploads request method=POST path=/2350--- PASS: TestUploadHandlersRejectInvalidKeys (0.17s)2351 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2352 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2353 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2354 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2355=== CONT TestPendingClosureWriteTimeout/empty2356=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline23572026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (3.58ms)23582026/10/01 10:24:15 WARN Failed to register uploaded object key=28zs3gpp87cc38c6nfv8rg3wn4pi50v4.narinfo error="server returned 404: 404 page not found\n"23592026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (3.51ms)23602026/10/01 10:24:15 INFO Upload complete. (73ms)23612026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000023622026/10/01 10:24:15 WARN Failed to register uploaded object key=3x85xbk7bvb1597v1mhxbf259mqw22nb.narinfo error="server returned 404: 404 page not found\n"23632026/10/01 10:24:15 INFO Received complete push request method=POST path=/api/pushes/1/complete23642026/10/01 10:24:15 WARN Failed to register uploaded object key=1cm2rzh9s3spczv3j37vy3jygfiarkis.narinfo error="server returned 404: 404 page not found\n"2365--- PASS: TestCacheStatsHandler (0.59s)2366=== CONT TestPendingClosureWriteTimeout/670k_objects2367=== CONT TestPendingClosureWriteTimeout/400_objects2368=== CONT TestProxyWriteTimeout/narinfo2369=== CONT TestProxyWriteTimeout/10_GiB_nar2370=== CONT TestProxyWriteTimeout/1_GiB_nar2371=== CONT TestProxyWriteTimeout/unknown_size2372--- PASS: TestProxyWriteTimeout (0.17s)2373 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2374 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2375 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2376 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2377=== CONT TestIsValidUploadKey/narinfo2378=== CONT TestIsValidUploadKey/unknown_type2379=== CONT TestIsValidUploadKey/empty_key2380=== CONT TestIsValidUploadKey/absolute2381=== CONT TestIsValidUploadKey/traversal_nar2382=== CONT TestIsValidUploadKey/traversal2383=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2384=== CONT TestIsValidUploadKey/nar_key,_narinfo_type23852026/10/01 10:24:15 OK 1_commit_pending_closure.sql (3.59ms)2386=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2387=== CONT TestIsValidUploadKey/build_log_home-manager_file23882026/10/01 10:24:15 OK 20241026095416_initial_model.sql (10.21ms)2389=== CONT TestIsValidUploadKey/build_log2390=== CONT TestIsValidUploadKey/listing2391=== CONT TestIsValidUploadKey/nar_plain2392=== CONT TestIsValidUploadKey/nar_xz2393=== CONT TestIsValidUploadKey/nar_zst2394=== CONT TestIsValidUploadKey/realisation_plus_in_output2395=== CONT TestIsValidUploadKey/build_log_plus_in_name2396=== CONT TestIsValidUploadKey/index.html2397=== CONT TestIsValidUploadKey/nix-cache-info2398=== CONT TestIsValidUploadKey/realisation2399=== CONT TestIsValidUploadKey/build_log_equals2400=== CONT TestIsValidUploadKey/build_log_question_mark2401--- PASS: TestIsValidUploadKey (0.18s)2402 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2403 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2404 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2405 --- PASS: TestIsValidUploadKey/absolute (0.00s)2406 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2407 --- PASS: TestIsValidUploadKey/traversal (0.00s)2408 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2409 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2410 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2411 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2412 --- PASS: TestIsValidUploadKey/build_log (0.00s)2413 --- PASS: TestIsValidUploadKey/listing (0.00s)2414 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2415 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2416 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2417 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2418 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2419 --- PASS: TestIsValidUploadKey/index.html (0.00s)2420 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2421 --- PASS: TestIsValidUploadKey/realisation (0.00s)2422 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2423 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2424=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows24252026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.76ms)24262026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)24272026-10-01 10:24:15.730 UTC [1148] ERROR: relation "goose_db_version" does not exist at character 3624282026-10-01 10:24:15.730 UTC [1148] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24292026/10/01 10:24:15 OK 3_commit_push.sql (2.29ms)24302026/10/01 10:24:15 goose: up to current file version: 324312026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.41ms)24322026/10/01 10:24:15 INFO Upload complete. (80ms)2433=== NAME TestClientMultipleUploads2434 client_integration_test.go:369: Uploaded 3 paths in 127.884517ms24352026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)24362026/10/01 10:24:15 OK 20260905000000_add_claims.sql (4.51ms)2437=== NAME TestClientCADerivations2438 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations467138057/001/store/l0r6vq8km7j9jw32xnp0kv216pwp6sdr-ca-test24392026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.84ms)2440--- PASS: TestClientMultipleUploads (0.89s)2441=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check24422026/10/01 10:24:15 OK 20241026095416_initial_model.sql (11.05ms)24432026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.73ms)24442026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000024452026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)24462026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.52ms)24472026/10/01 10:24:15 OK 20251218171726_add_pins.sql (4.74ms)24482026/10/01 10:24:15 OK 2_object_stats_trigger.sql (2.84ms)24492026/10/01 10:24:15 OK 3_commit_push.sql (2.92ms)24502026/10/01 10:24:15 goose: up to current file version: 324512026/10/01 10:24:15 INFO All 1 paths already cached2452=== NAME TestClientIntegration2453 client_integration_test.go:312: Retrieved narinfo from S3:2454 StorePath: /build/TestClientIntegration3862171716/002/store/iqrjl13yh6zf6vfpi0dgc14qjx1dy4m0-test-file.txt2455 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2456 Compression: zstd2457 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12458 NarSize: 1522459 References: 2460 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12461 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2462 client_integration_test.go:313: Decompressed .ls content (64 bytes):2463 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2464 client_integration_test.go:316: Testing garbage collection...24652026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (12.63ms)24662026/10/01 10:24:15 OK 20260905000000_add_claims.sql (5.19ms)24672026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.97ms)24682026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.77ms)24692026/10/01 10:24:15 goose: successfully migrated database to version: 202609231200002470=== NAME TestClientCADerivations2471 client_ca_test.go:139: Found 1 dependencies (including self)24722026-10-01 10:24:15.780 UTC [1206] ERROR: relation "goose_db_version" does not exist at character 3624732026-10-01 10:24:15.780 UTC [1206] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24742026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.61ms)24752026/10/01 10:24:15 OK 2_object_stats_trigger.sql (2.12ms)24762026/10/01 10:24:15 OK 3_commit_push.sql (3.02ms)24772026/10/01 10:24:15 goose: up to current file version: 324782026/10/01 10:24:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures24792026/10/01 10:24:15 INFO Garbage collection started24802026/10/01 10:24:15 OK 20241026095416_initial_model.sql (13.94ms)24812026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)24822026/10/01 10:24:15 INFO Aborted multipart uploads count=0 kept=024832026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.48ms)24842026/10/01 10:24:15 WARN Force mode enabled - objects will be deleted immediately without grace period24852026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)24862026-10-01 10:24:15.810 UTC [1261] ERROR: relation "goose_db_version" does not exist at character 3624872026-10-01 10:24:15.810 UTC [1261] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24882026/10/01 10:24:15 OK 20260905000000_add_claims.sql (3.42ms)24892026-10-01 10:24:15.813 UTC [1263] ERROR: relation "goose_db_version" does not exist at character 3624902026-10-01 10:24:15.813 UTC [1263] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24912026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (3.07ms)24922026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (10.31ms)24932026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000024942026/10/01 10:24:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=024952026-10-01 10:24:15.828 UTC [1281] ERROR: relation "goose_db_version" does not exist at character 3624962026-10-01 10:24:15.828 UTC [1281] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24972026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.61ms)24982026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.16ms)24992026/10/01 10:24:15 INFO Vacuumed table table=pending_closures2500--- PASS: TestGCBugBareHashReferences (0.82s)2501=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure25022026/10/01 10:24:15 INFO Received uploads request method=POST path=/25032026/10/01 10:24:15 OK 3_commit_push.sql (1.72ms)25042026/10/01 10:24:15 goose: up to current file version: 325052026/10/01 10:24:15 INFO lead: released remote=192.0.2.1:123425062026/10/01 10:24:15 INFO Vacuumed table table=pending_objects25072026/10/01 10:24:15 INFO Vacuumed table table=multipart_uploads25082026/10/01 10:24:15 OK 20241026095416_initial_model.sql (9.84ms)25092026/10/01 10:24:15 OK 20241026095416_initial_model.sql (8.76ms)25102026-10-01 10:24:15.837 UTC [1284] ERROR: relation "goose_db_version" does not exist at character 3625112026-10-01 10:24:15.837 UTC [1284] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25122026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)25132026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)25142026/10/01 10:24:15 INFO Vacuumed table table=closures25152026-10-01 10:24:15.840 UTC [1285] ERROR: relation "goose_db_version" does not exist at character 3625162026-10-01 10:24:15.840 UTC [1285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25172026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.01ms)25182026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.85ms)25192026/10/01 10:24:15 INFO Vacuumed table table=objects25202026/10/01 10:24:15 OK 20241026095416_initial_model.sql (9.6ms)25212026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (2.73ms)25222026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)25232026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)2524=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token25252026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.63ms)2526=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2527=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2528=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2529=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2530=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2531=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2532=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2533=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts25342026/10/01 10:24:15 INFO Received request for more parts method=POST path=/25352026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.91ms)25362026/10/01 10:24:15 OK 20251218171726_add_pins.sql (3.21ms)25372026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.27ms)25382026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (1.57ms)25392026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.01ms)25402026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000025412026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)25422026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (2.34ms)25432026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000025442026/10/01 10:24:15 OK 20241026095416_initial_model.sql (8.53ms)25452026-10-01 10:24:15.854 UTC [1337] ERROR: relation "goose_db_version" does not exist at character 3625462026-10-01 10:24:15.854 UTC [1337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25472026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.05ms)25482026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)25492026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.49ms)25502026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.74ms)25512026/10/01 10:24:15 OK 20241026095416_initial_model.sql (8.46ms)25522026/10/01 10:24:15 OK 2_object_stats_trigger.sql (752.86µs)25532026/10/01 10:24:15 OK 2_object_stats_trigger.sql (766.56µs)25542026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)25552026/10/01 10:24:15 OK 3_commit_push.sql (535.32µs)25562026/10/01 10:24:15 goose: up to current file version: 325572026/10/01 10:24:15 OK 3_commit_push.sql (796.99µs)25582026/10/01 10:24:15 goose: up to current file version: 325592026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (1.84ms)25602026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.14ms)25612026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (1.9ms)25622026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000025632026/10/01 10:24:15 OK 20251218171726_add_pins.sql (2.51ms)25642026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (2.22ms)25652026/10/01 10:24:15 OK 1_commit_pending_closure.sql (1.73ms)25662026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.72ms)25672026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.7ms)25682026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)25692026/10/01 10:24:15 OK 3_commit_push.sql (925.26µs)25702026/10/01 10:24:15 goose: up to current file version: 325712026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (2.09ms)25722026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.44ms)25732026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (1.16ms)25742026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000025752026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (1.43ms)25762026/10/01 10:24:15 OK 20241026095416_initial_model.sql (7.45ms)25772026/10/01 10:24:15 OK 1_commit_pending_closure.sql (1.74ms)25782026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (1.18ms)25792026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000025802026/10/01 10:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)25812026/10/01 10:24:15 OK 2_object_stats_trigger.sql (776.28µs)25822026/10/01 10:24:15 OK 1_commit_pending_closure.sql (1.59ms)25832026/10/01 10:24:15 OK 3_commit_push.sql (1.05ms)25842026/10/01 10:24:15 goose: up to current file version: 325852026/10/01 10:24:15 OK 20251218171726_add_pins.sql (1.84ms)25862026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.01ms)2587--- PASS: TestService_ReadScope_PublicByDefault (0.39s)2588=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25892026/10/01 10:24:15 OK 3_commit_push.sql (1.33ms)25902026/10/01 10:24:15 goose: up to current file version: 325912026/10/01 10:24:15 INFO Received complete multipart upload request method=POST path=/25922026/10/01 10:24:15 OK 20260628120000_add_object_size_and_stats.sql (2.48ms)25932026/10/01 10:24:15 OK 20260905000000_add_claims.sql (2.92ms)25942026/10/01 10:24:15 OK 20260920000000_drop_claims.sql (1.67ms)25952026/10/01 10:24:15 OK 20260923120000_add_pushes.sql (1.9ms)25962026/10/01 10:24:15 goose: successfully migrated database to version: 2026092312000025972026/10/01 10:24:15 OK 1_commit_pending_closure.sql (2.18ms)25982026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes25992026/10/01 10:24:15 OK 2_object_stats_trigger.sql (1.25ms)26002026/10/01 10:24:15 INFO lead: acquired remote=192.0.2.1:123426012026/10/01 10:24:15 OK 3_commit_push.sql (624.85µs)26022026/10/01 10:24:15 goose: up to current file version: 326032026/10/01 10:24:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26042026/10/01 10:24:15 INFO Uploading l0r6vq8km7j9jw32xnp0kv216pwp6sdr-ca-test (144B)26052026/10/01 10:24:15 INFO lead: released remote=192.0.2.1:12342606--- PASS: TestLeadElectsOneAndHandsOver (0.81s)2607=== CONT TestPush_RejectsBadRequests/no_roots26082026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes2609=== CONT TestPush_RejectsBadRequests/no_objects26102026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes2611=== CONT TestPush_RejectsBadRequests/bad_root26122026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes2613=== CONT TestPush_RejectsBadRequests/root_not_in_objects26142026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes2615=== CONT TestIsValidCachePath/empty2616=== CONT TestIsValidCachePath/narinfo2617=== CONT TestIsValidCachePath/nix-cache-info2618--- PASS: TestPush_RejectsBadRequests (0.64s)2619 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2620 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2621 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2622 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)26232026/10/01 10:24:15 WARN Failed to register uploaded object key=l0r6vq8km7j9jw32xnp0kv216pwp6sdr.ls error="server returned 404: 404 page not found\n"2624=== CONT TestIsValidCachePath/realisation26252026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"2626=== CONT TestIsValidCachePath/log2627=== CONT TestIsValidCachePath/ls2628=== CONT TestIsValidCachePath/nar_uncompressed2629=== CONT TestIsValidCachePath/nar_bz22630=== CONT TestIsValidCachePath/index.html2631=== CONT TestIsValidCachePath/nar_xz2632=== CONT TestIsValidCachePath/nar_zst26332026/10/01 10:24:15 WARN Failed to register uploaded object key=log/1x9giz3ml0lkwch9689g6r4pc5ix57sp-ca-test.drv error="server returned 404: 404 page not found\n"2634=== CONT TestIsValidCachePath/random_path26352026/10/01 10:24:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2636=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2637=== CONT TestIsValidCachePath/invalid_char_u2638=== CONT TestIsValidCachePath/invalid_char_e2639=== CONT TestIsValidCachePath/traversal_parent2640=== CONT TestIsValidCachePath/wrong_extension2641=== CONT TestIsValidCachePath/short_hash2642=== CONT TestIsValidCachePath/traversal_in_middle2643=== CONT TestIsValidCachePath/leading_slash26442026/10/01 10:24:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"2645=== CONT TestParseSingleRange/none26462026/10/01 10:24:15 WARN mTLS auth: bound subjects configured but subject DN unavailable2647--- PASS: TestIsValidCachePath (0.00s)2648 --- PASS: TestIsValidCachePath/empty (0.00s)2649 --- PASS: TestIsValidCachePath/narinfo (0.00s)2650 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2651 --- PASS: TestIsValidCachePath/realisation (0.00s)2652 --- PASS: TestIsValidCachePath/log (0.00s)2653 --- PASS: TestIsValidCachePath/ls (0.00s)2654 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2655 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2656 --- PASS: TestIsValidCachePath/index.html (0.00s)2657 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2658 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2659 --- PASS: TestIsValidCachePath/random_path (0.00s)2660 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2661 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2662 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2663 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2664 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2665 --- PASS: TestIsValidCachePath/short_hash (0.00s)2666 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2667 --- PASS: TestIsValidCachePath/leading_slash (0.00s)26682026/10/01 10:24:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2669=== CONT TestParseSingleRange/open-ended26702026/10/01 10:24:15 INFO Signed narinfos id=1 count=12671=== CONT TestParseSingleRange/start_past_EOF2672=== CONT TestParseSingleRange/single_byte2673=== CONT TestParseSingleRange/suffix_exceeds_size2674=== CONT TestParseSingleRange/suffix2675=== CONT TestParseSingleRange/end_clamped_to_size26762026/10/01 10:24:15 INFO Uploading 1 narinfos2677=== CONT TestParseSingleRange/closed2678=== CONT TestParseSingleRange/multi-range_ignored2679=== CONT TestParseSingleRange/malformed_both_empty2680=== CONT TestParseSingleRange/malformed_no_dash2681--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.31s)2682=== CONT TestParseSingleRange/start_far_past_EOF2683=== CONT TestParseSingleRange/unknown_unit2684=== CONT TestParseSingleRange/malformed_end_before_start2685--- PASS: TestParseSingleRange (0.00s)2686 --- PASS: TestParseSingleRange/none (0.00s)2687 --- PASS: TestParseSingleRange/open-ended (0.00s)2688 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2689 --- PASS: TestParseSingleRange/single_byte (0.00s)2690 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2691 --- PASS: TestParseSingleRange/suffix (0.00s)2692 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2693 --- PASS: TestParseSingleRange/closed (0.00s)2694 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2695 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2696 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2697 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2698 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2699 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2700=== CONT TestServerTLSConfig/no_client_CA2701=== CONT TestServerTLSConfig/not_a_PEM_file2702=== CONT TestServerTLSConfig/missing_CA_file2703=== CONT TestCacheConfigHandler/full_config,_no_issuer2704=== CONT TestCacheConfigHandler/no_signing_keys2705=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2706=== CONT TestCacheConfigHandler/no_cache_url_configured2707--- PASS: TestCacheConfigHandler (0.00s)2708 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2709 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2710 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2711 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2712=== CONT TestClientErrorHandling/InvalidStorePath2713--- PASS: TestServerTLSConfig (0.00s)2714 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2715 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2716 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2717=== CONT TestClientErrorHandling/InvalidAuthToken27182026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes27192026/10/01 10:24:15 INFO Received complete push request method=POST path=/api/pushes/1/complete27202026/10/01 10:24:15 WARN Failed to register uploaded object key=l0r6vq8km7j9jw32xnp0kv216pwp6sdr.narinfo error="server returned 404: 404 page not found\n"27212026/10/01 10:24:15 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)27222026/10/01 10:24:15 INFO Uploading 6pwgbcp40gl6y7h5djn0fdc7fdr76a1l-top (224B)27232026/10/01 10:24:15 INFO Uploading dqkmwx78q33kqi461f4wmbz5ni3p2w7v-shared-dep (136B)27242026/10/01 10:24:15 INFO Upload complete. (93ms)2725=== CONT TestClientErrorHandling/ServerNotAvailable2726=== NAME TestClientCADerivations2727 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations467138057/001/store/l0r6vq8km7j9jw32xnp0kv216pwp6sdr-ca-test2728 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2729 Compression: zstd2730 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n27312026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/10ck8kmp5avzbglr2p22a91854f74b44j46fcajdxcs5svx7l4wz.nar.zst error="server returned 404: 404 page not found\n"2732 NarSize: 1442733 References: 27342026/10/01 10:24:15 WARN Failed to register uploaded object key=dqkmwx78q33kqi461f4wmbz5ni3p2w7v.ls error="server returned 404: 404 page not found\n"2735 Deriver: /build/TestClientCADerivations467138057/001/store/1x9giz3ml0lkwch9689g6r4pc5ix57sp-ca-test.drv2736 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2737 client_ca_test.go:185: Checking for realisation files in S3...27382026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"27392026/10/01 10:24:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27402026/10/01 10:24:15 INFO Signed narinfos id=1 count=227412026/10/01 10:24:15 WARN Failed to register uploaded object key=6pwgbcp40gl6y7h5djn0fdc7fdr76a1l.ls error="server returned 404: 404 page not found\n"2742 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations27432026/10/01 10:24:15 INFO Uploading 2 narinfos2744 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache27452026/10/01 10:24:15 WARN Failed to register uploaded object key=6pwgbcp40gl6y7h5djn0fdc7fdr76a1l.narinfo error="server returned 404: 404 page not found\n"27462026/10/01 10:24:15 INFO Received complete push request method=POST path=/api/pushes/1/complete27472026/10/01 10:24:15 WARN Failed to register uploaded object key=dqkmwx78q33kqi461f4wmbz5ni3p2w7v.narinfo error="server returned 404: 404 page not found\n"2748--- PASS: TestService_ReadAuthMiddleware (0.30s)2749=== CONT TestResolveDBConnectionString/flag_wins2750=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2751=== CONT TestResolveDBConnectionString/nothing_configured2752=== CONT TestResolveDBConnectionString/missing_file_is_an_error2753=== CONT TestResolveDBConnectionString/file_when_flag_empty2754=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2755--- PASS: TestResolveDBConnectionString (0.00s)2756 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2757 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2758 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2759 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2760 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2761=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected27622026/10/01 10:24:15 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]2763=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2764=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27652026/10/01 10:24:15 WARN Authentication failed token_preview=eyJhbGciOi...Q6E6ydmVqw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2766--- PASS: TestService_AuthMiddleware_OIDC (0.54s)2767 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2768 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2769 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2770 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)27712026/10/01 10:24:15 INFO Upload complete. (66ms)2772=== NAME TestClientSharedPathCommittedMidPush2773 client_integration_test.go:680: Retrieved narinfo from S3:2774 StorePath: /build/TestClientSharedPathCommittedMidPush825024634/001/store/dqkmwx78q33kqi461f4wmbz5ni3p2w7v-shared-dep2775 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2776 Compression: zstd2777 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822778 NarSize: 1362779 References: 2780 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2781 client_integration_test.go:680: Retrieved narinfo from S3:2782 StorePath: /build/TestClientSharedPathCommittedMidPush825024634/001/store/6pwgbcp40gl6y7h5djn0fdc7fdr76a1l-top2783 URL: nar/10ck8kmp5avzbglr2p22a91854f74b44j46fcajdxcs5svx7l4wz.nar.zst2784 Compression: zstd2785 NarHash: sha256:10ck8kmp5avzbglr2p22a91854f74b44j46fcajdxcs5svx7l4wz2786 NarSize: 2242787 References: /build/TestClientSharedPathCommittedMidPush825024634/001/store/dqkmwx78q33kqi461f4wmbz5ni3p2w7v-shared-dep2788 CA: text:sha256:1g532nkxdpj5fa4i0wx4r4iii7n0prqlk2x89sc8mzfrifgm2ipa2789--- PASS: TestClientSharedPathCommittedMidPush (0.77s)2790--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.31s)27912026/10/01 10:24:15 INFO Received push request method=POST path=/api/pushes27922026/10/01 10:24:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)27932026/10/01 10:24:15 INFO Uploading z00vg9qlasxzy5qqgxwv6xnlardkn6si-a (216B)27942026/10/01 10:24:15 INFO Uploading gqrs364kizkw7maf2d3dzfbw5l09il0v-shared-dep (136B)27952026/10/01 10:24:15 WARN Failed to register uploaded object key=maq26911c474rxrw29b1lnsm09f7gmsi.ls error="server returned 404: 404 page not found\n"27962026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"27972026/10/01 10:24:15 WARN Failed to register uploaded object key=nar/15psg7bw9irkg6yajfqzy6pa3sv7g6604hiq2rbq49fjsbbgjag5.nar.zst error="server returned 404: 404 page not found\n"27982026/10/01 10:24:15 WARN Failed to register uploaded object key=z00vg9qlasxzy5qqgxwv6xnlardkn6si.ls error="server returned 404: 404 page not found\n"27992026/10/01 10:24:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28002026/10/01 10:24:15 WARN Failed to register uploaded object key=gqrs364kizkw7maf2d3dzfbw5l09il0v.ls error="server returned 404: 404 page not found\n"28012026/10/01 10:24:15 INFO Signed narinfos id=1 count=328022026/10/01 10:24:15 INFO Uploading 3 narinfos2803--- PASS: TestMetricsInventory (0.31s)28042026/10/01 10:24:15 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/present28052026/10/01 10:24:15 WARN Failed to register uploaded object key=z00vg9qlasxzy5qqgxwv6xnlardkn6si.narinfo error="server returned 404: 404 page not found\n"28062026/10/01 10:24:15 WARN Failed to register uploaded object key=gqrs364kizkw7maf2d3dzfbw5l09il0v.narinfo error="server returned 404: 404 page not found\n"28072026/10/01 10:24:15 INFO Received complete push request method=POST path=/api/pushes/1/complete28082026/10/01 10:24:15 WARN Failed to register uploaded object key=maq26911c474rxrw29b1lnsm09f7gmsi.narinfo error="server returned 404: 404 page not found\n"28092026/10/01 10:24:15 INFO Upload complete. (64ms)2810=== NAME TestClientPushesUseOnePush2811 client_pushes_test.go:97: Retrieved narinfo from S3:2812 StorePath: /build/TestClientPushesUseOnePush2218600205/001/store/gqrs364kizkw7maf2d3dzfbw5l09il0v-shared-dep2813 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2814 Compression: zstd2815 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822816 NarSize: 1362817 References: 2818 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2819 client_pushes_test.go:97: Retrieved narinfo from S3:2820 StorePath: /build/TestClientPushesUseOnePush2218600205/001/store/z00vg9qlasxzy5qqgxwv6xnlardkn6si-a2821 URL: nar/15psg7bw9irkg6yajfqzy6pa3sv7g6604hiq2rbq49fjsbbgjag5.nar.zst2822 Compression: zstd2823 NarHash: sha256:15psg7bw9irkg6yajfqzy6pa3sv7g6604hiq2rbq49fjsbbgjag52824 NarSize: 2162825 References: /build/TestClientPushesUseOnePush2218600205/001/store/gqrs364kizkw7maf2d3dzfbw5l09il0v-shared-dep2826 CA: text:sha256:0cvd265j7ifrgqfp9gwwx20v7nb8z770xfngz73yjdcf2xff56xn28272026-10-01 10:24:15.992 UTC [1684] ERROR: relation "goose_db_version" does not exist at character 3628282026-10-01 10:24:15.992 UTC [1684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2829 client_pushes_test.go:97: Retrieved narinfo from S3:2830 StorePath: /build/TestClientPushesUseOnePush2218600205/001/store/maq26911c474rxrw29b1lnsm09f7gmsi-b2831 URL: nar/15psg7bw9irkg6yajfqzy6pa3sv7g6604hiq2rbq49fjsbbgjag5.nar.zst2832 Compression: zstd2833 NarHash: sha256:15psg7bw9irkg6yajfqzy6pa3sv7g6604hiq2rbq49fjsbbgjag52834 NarSize: 2162835 References: /build/TestClientPushesUseOnePush2218600205/001/store/gqrs364kizkw7maf2d3dzfbw5l09il0v-shared-dep2836 CA: text:sha256:0cvd265j7ifrgqfp9gwwx20v7nb8z770xfngz73yjdcf2xff56xn28372026-10-01 10:24:15.997 UTC [1683] ERROR: relation "goose_db_version" does not exist at character 3628382026-10-01 10:24:15.997 UTC [1683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2839--- PASS: TestClientPushesUseOnePush (0.76s)28402026/10/01 10:24:16 OK 20241026095416_initial_model.sql (7.52ms)28412026/10/01 10:24:16 OK 20251210153512_drop_unused_gin_index.sql (958.28µs)28422026/10/01 10:24:16 OK 20251218171726_add_pins.sql (2.54ms)28432026/10/01 10:24:16 OK 20260628120000_add_object_size_and_stats.sql (2.64ms)28442026/10/01 10:24:16 OK 20260905000000_add_claims.sql (2.69ms)28452026/10/01 10:24:16 OK 20260920000000_drop_claims.sql (1.59ms)28462026/10/01 10:24:16 OK 20260923120000_add_pushes.sql (1.08ms)28472026/10/01 10:24:16 goose: successfully migrated database to version: 2026092312000028482026/10/01 10:24:16 OK 1_commit_pending_closure.sql (1.7ms)28492026/10/01 10:24:16 OK 2_object_stats_trigger.sql (563.25µs)28502026/10/01 10:24:16 OK 20241026095416_initial_model.sql (14.96ms)28512026/10/01 10:24:16 OK 3_commit_push.sql (659.06µs)28522026/10/01 10:24:16 goose: up to current file version: 328532026/10/01 10:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)28542026/10/01 10:24:16 INFO Received uploads request method=POST path=/api/pending_closures28552026/10/01 10:24:16 OK 20251218171726_add_pins.sql (3.69ms)28562026/10/01 10:24:16 INFO Received uploads request method=POST path=/api/pending_closures28572026/10/01 10:24:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)28582026/10/01 10:24:16 INFO Uploading 0y6p2vzy484zdg0mna4vrck0wjkdk58g-shared-dep (136B)28592026/10/01 10:24:16 INFO Uploading am594c5m493jiisyj5jy1sxk2irb2l3l-b (216B)2860=== NAME TestClientCADerivations2861 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2862 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2863 error: binary cache 's3://bucket67?endpoint=http://localhost:40789®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations467138057/001/store'2864 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 128652026/10/01 10:24:16 WARN Failed to register uploaded object key=5d4q0crbx9gavr96h7d91vf5cjxsjqcy.ls error="server returned 404: 404 page not found\n"28662026/10/01 10:24:16 OK 20260628120000_add_object_size_and_stats.sql (7.24ms)28672026/10/01 10:24:16 WARN Failed to register uploaded object key=am594c5m493jiisyj5jy1sxk2irb2l3l.ls error="server returned 404: 404 page not found\n"28682026/10/01 10:24:16 WARN Failed to register uploaded object key=nar/0sckjxcfasr19nm1jkcjlss1rlbgg0242hbcg7q1s64v81w0qdhr.nar.zst error="server returned 404: 404 page not found\n"28692026/10/01 10:24:16 WARN Failed to register uploaded object key=0y6p2vzy484zdg0mna4vrck0wjkdk58g.ls error="server returned 404: 404 page not found\n"2870--- PASS: TestClientCADerivations (0.97s)28712026/10/01 10:24:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"28722026/10/01 10:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign28732026/10/01 10:24:16 INFO Signed narinfos id=1 count=228742026/10/01 10:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign28752026/10/01 10:24:16 INFO Signed narinfos id=2 count=228762026/10/01 10:24:16 INFO Uploading 4 narinfos28772026/10/01 10:24:16 OK 20260905000000_add_claims.sql (4.34ms)28782026/10/01 10:24:16 WARN Failed to register uploaded object key=am594c5m493jiisyj5jy1sxk2irb2l3l.narinfo error="server returned 404: 404 page not found\n"28792026/10/01 10:24:16 WARN Failed to register uploaded object key=0y6p2vzy484zdg0mna4vrck0wjkdk58g.narinfo error="server returned 404: 404 page not found\n"28802026/10/01 10:24:16 OK 20260920000000_drop_claims.sql (2.39ms)28812026/10/01 10:24:16 WARN Failed to register uploaded object key=5d4q0crbx9gavr96h7d91vf5cjxsjqcy.narinfo error="server returned 404: 404 page not found\n"28822026/10/01 10:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete28832026/10/01 10:24:16 WARN Failed to register uploaded object key=0y6p2vzy484zdg0mna4vrck0wjkdk58g.narinfo error="server returned 404: 404 page not found\n"28842026/10/01 10:24:16 OK 20260923120000_add_pushes.sql (1.79ms)28852026/10/01 10:24:16 goose: successfully migrated database to version: 2026092312000028862026/10/01 10:24:16 OK 1_commit_pending_closure.sql (2.24ms)28872026/10/01 10:24:16 INFO Completed upload id=228882026/10/01 10:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete28892026/10/01 10:24:16 OK 2_object_stats_trigger.sql (935.75µs)2890=== NAME TestNARDeduplicationMetadataUploadBug28912026/10/01 10:24:16 INFO Completed upload id=12892 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3428796747/001/store/hqr55x2s9qf98hgjqcvh81k8vsdy6mfw-file1.txt28932026/10/01 10:24:16 INFO Upload complete. (60ms)28942026/10/01 10:24:16 OK 3_commit_push.sql (795.02µs)28952026/10/01 10:24:16 goose: up to current file version: 32896=== NAME TestClientFallsBackToClosures2897 client_pushes_test.go:112: Retrieved narinfo from S3:2898 StorePath: /build/TestClientFallsBackToClosures167414129/001/store/0y6p2vzy484zdg0mna4vrck0wjkdk58g-shared-dep2899 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2900 Compression: zstd2901 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822902 NarSize: 1362903 References: 2904 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2905 client_pushes_test.go:112: Retrieved narinfo from S3:2906 StorePath: /build/TestClientFallsBackToClosures167414129/001/store/5d4q0crbx9gavr96h7d91vf5cjxsjqcy-a2907 URL: nar/0sckjxcfasr19nm1jkcjlss1rlbgg0242hbcg7q1s64v81w0qdhr.nar.zst2908 Compression: zstd2909 NarHash: sha256:0sckjxcfasr19nm1jkcjlss1rlbgg0242hbcg7q1s64v81w0qdhr2910 NarSize: 2162911 References: /build/TestClientFallsBackToClosures167414129/001/store/0y6p2vzy484zdg0mna4vrck0wjkdk58g-shared-dep2912 CA: text:sha256:0r3lbqws8bf3432vqzvypzv09kbslhrbs4ld1jl5h06kyd45idrj2913 client_pushes_test.go:112: Retrieved narinfo from S3:2914 StorePath: /build/TestClientFallsBackToClosures167414129/001/store/am594c5m493jiisyj5jy1sxk2irb2l3l-b2915 URL: nar/0sckjxcfasr19nm1jkcjlss1rlbgg0242hbcg7q1s64v81w0qdhr.nar.zst2916 Compression: zstd2917 NarHash: sha256:0sckjxcfasr19nm1jkcjlss1rlbgg0242hbcg7q1s64v81w0qdhr2918 NarSize: 2162919 References: /build/TestClientFallsBackToClosures167414129/001/store/0y6p2vzy484zdg0mna4vrck0wjkdk58g-shared-dep2920 CA: text:sha256:0r3lbqws8bf3432vqzvypzv09kbslhrbs4ld1jl5h06kyd45idrj2921=== NAME TestPinProtectsFromGC2922 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1235448722/001/store/3m9k4fql9dyz24kvl6zzv50ygl6a3lg5-pinned-file.txt2923 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1235448722/001/store/1vkc7msypw4wpc2f1n384096ww2xmk2z-unpinned-file.txt2924=== RUN TestService_RequireScope_OIDC/builder_may_write2925=== PAUSE TestService_RequireScope_OIDC/builder_may_write2926=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2927=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2928=== RUN TestService_RequireScope_OIDC/ops_may_admin2929=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2930=== RUN TestService_RequireScope_OIDC/ops_may_not_write2931=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2932=== RUN TestService_RequireScope_OIDC/reader_may_not_write2933=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2934=== RUN TestService_RequireScope_OIDC/static_token_may_admin2935=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2936=== RUN TestService_RequireScope_OIDC/static_token_may_write2937=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2938=== RUN TestService_RequireScope_OIDC/reader_may_read2939=== PAUSE TestService_RequireScope_OIDC/reader_may_read2940=== RUN TestService_RequireScope_OIDC/writer_implies_read2941=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2942=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2943=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2944=== CONT TestService_RequireScope_OIDC/builder_may_write2945=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2946=== CONT TestService_RequireScope_OIDC/static_token_may_admin2947=== CONT TestService_RequireScope_OIDC/writer_implies_read2948=== CONT TestService_RequireScope_OIDC/reader_may_read2949=== CONT TestService_RequireScope_OIDC/ops_may_not_write2950=== CONT TestService_RequireScope_OIDC/static_token_may_write2951=== CONT TestService_RequireScope_OIDC/ops_may_admin2952=== CONT TestService_RequireScope_OIDC/reader_may_not_write2953=== CONT TestService_RequireScope_OIDC/builder_may_not_admin29542026/10/01 10:24:16 INFO Received uploads request method=POST path=/api/pending_closures2955--- PASS: TestService_RequireScope_OIDC (0.56s)2956 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2957 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2958 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2959 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2960 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2961 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2962 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2963 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2964 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2965 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2966--- PASS: TestClientFallsBackToClosures (0.67s)29672026/10/01 10:24:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.136963ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29682026/10/01 10:24:16 INFO Received uploads request method=POST path=/api/pending_closures29692026/10/01 10:24:16 INFO Aborted multipart uploads count=0 kept=029702026/10/01 10:24:16 WARN Force mode enabled - objects will be deleted immediately without grace period29712026/10/01 10:24:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=029722026/10/01 10:24:16 INFO Vacuumed table table=pending_closures29732026/10/01 10:24:16 INFO Vacuumed table table=pending_objects29742026/10/01 10:24:16 INFO Vacuumed table table=multipart_uploads29752026/10/01 10:24:16 INFO Vacuumed table table=closures29762026/10/01 10:24:16 INFO Received uploads request method=POST path=/api/pending_closures29772026/10/01 10:24:16 INFO Vacuumed table table=objects29782026/10/01 10:24:16 INFO Received push request method=POST path=/api/pushes29792026/10/01 10:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29802026/10/01 10:24:16 INFO Uploading hqr55x2s9qf98hgjqcvh81k8vsdy6mfw-file1.txt (160B)29812026/10/01 10:24:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"29822026/10/01 10:24:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29832026/10/01 10:24:16 INFO Signed narinfos id=1 count=129842026/10/01 10:24:16 WARN Failed to register uploaded object key=hqr55x2s9qf98hgjqcvh81k8vsdy6mfw.ls error="server returned 404: 404 page not found\n"29852026/10/01 10:24:16 INFO Uploading 1 narinfos29862026/10/01 10:24:16 INFO Received push request method=POST path=/api/pushes29872026/10/01 10:24:16 INFO Received complete push request method=POST path=/api/pushes/1/complete29882026/10/01 10:24:16 WARN Failed to register uploaded object key=hqr55x2s9qf98hgjqcvh81k8vsdy6mfw.narinfo error="server returned 404: 404 page not found\n"29892026/10/01 10:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29902026/10/01 10:24:16 INFO Uploading 3m9k4fql9dyz24kvl6zzv50ygl6a3lg5-pinned-file.txt (128B)29912026/10/01 10:24:16 INFO Upload complete. (51ms)2992=== NAME TestNARDeduplicationMetadataUploadBug2993 metadata_upload_test.go:54: Retrieved narinfo from S3:2994 StorePath: /build/TestNARDeduplicationMetadataUploadBug3428796747/001/store/hqr55x2s9qf98hgjqcvh81k8vsdy6mfw-file1.txt2995 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2996 Compression: zstd2997 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2998 NarSize: 1602999 References: 3000 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3001 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)3002 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):3003 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}30042026/10/01 10:24:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"30052026/10/01 10:24:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign30062026/10/01 10:24:16 WARN Failed to register uploaded object key=3m9k4fql9dyz24kvl6zzv50ygl6a3lg5.ls error="server returned 404: 404 page not found\n"30072026/10/01 10:24:16 INFO Signed narinfos id=1 count=130082026/10/01 10:24:16 INFO Uploading 1 narinfos30092026/10/01 10:24:16 INFO Received complete push request method=POST path=/api/pushes/1/complete30102026/10/01 10:24:16 WARN Failed to register uploaded object key=3m9k4fql9dyz24kvl6zzv50ygl6a3lg5.narinfo error="server returned 404: 404 page not found\n"30112026/10/01 10:24:16 INFO Upload complete. (57ms)3012 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3428796747/001/store/zhj5lm651zvjylicwk7q7yyr17mydak2-file2.txt3013--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.81s)30142026/10/01 10:24:16 INFO Aborted multipart uploads count=0 kept=030152026/10/01 10:24:16 WARN Force mode enabled - objects will be deleted immediately without grace period30162026/10/01 10:24:16 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=030172026/10/01 10:24:16 INFO Vacuumed table table=pending_closures30182026/10/01 10:24:16 INFO Vacuumed table table=pending_objects30192026/10/01 10:24:16 INFO Vacuumed table table=multipart_uploads30202026/10/01 10:24:16 INFO Vacuumed table table=closures30212026/10/01 10:24:16 INFO Vacuumed table table=objects3022--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)3023 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.46s)3024 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.45s)30252026/10/01 10:24:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30262026/10/01 10:24:16 INFO Received push request method=POST path=/api/pushes30272026/10/01 10:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)30282026/10/01 10:24:16 INFO Uploading 1vkc7msypw4wpc2f1n384096ww2xmk2z-unpinned-file.txt (128B)30292026/10/01 10:24:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"30302026/10/01 10:24:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign30312026/10/01 10:24:16 INFO Signed narinfos id=2 count=130322026/10/01 10:24:16 WARN Failed to register uploaded object key=1vkc7msypw4wpc2f1n384096ww2xmk2z.ls error="server returned 404: 404 page not found\n"30332026/10/01 10:24:16 INFO Uploading 1 narinfos30342026/10/01 10:24:16 INFO Received complete push request method=POST path=/api/pushes/2/complete30352026/10/01 10:24:16 WARN Failed to register uploaded object key=1vkc7msypw4wpc2f1n384096ww2xmk2z.narinfo error="server returned 404: 404 page not found\n"30362026/10/01 10:24:16 INFO Upload complete. (48ms)30372026/10/01 10:24:16 INFO Received push request method=POST path=/api/pushes30382026/10/01 10:24:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)30392026/10/01 10:24:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign30402026/10/01 10:24:16 WARN Failed to register uploaded object key=zhj5lm651zvjylicwk7q7yyr17mydak2.ls error="server returned 404: 404 page not found\n"30412026/10/01 10:24:16 INFO Signed narinfos id=2 count=130422026/10/01 10:24:16 INFO Uploading 1 narinfos30432026/10/01 10:24:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30442026/10/01 10:24:16 INFO Received complete push request method=POST path=/api/pushes/2/complete30452026/10/01 10:24:16 WARN Failed to register uploaded object key=zhj5lm651zvjylicwk7q7yyr17mydak2.narinfo error="server returned 404: 404 page not found\n"30462026/10/01 10:24:16 INFO Upload complete. (45ms)3047=== NAME TestNARDeduplicationMetadataUploadBug3048 metadata_upload_test.go:76: Retrieved narinfo from S3:3049 StorePath: /build/TestNARDeduplicationMetadataUploadBug3428796747/001/store/zhj5lm651zvjylicwk7q7yyr17mydak2-file2.txt3050 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst3051 Compression: zstd3052 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3053 NarSize: 1603054 References: 3055 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3056 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)3057 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):3058 {"version":1,"root":{"type":"regular","size":44}}3059--- PASS: TestNARDeduplicationMetadataUploadBug (0.57s)30602026/10/01 10:24:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures30612026/10/01 10:24:16 INFO Garbage collection started30622026/10/01 10:24:16 INFO Aborted multipart uploads count=0 kept=030632026/10/01 10:24:16 WARN Force mode enabled - objects will be deleted immediately without grace period30642026/10/01 10:24:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=389.324049ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30652026/10/01 10:24:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=030662026/10/01 10:24:16 INFO Vacuumed table table=pending_closures30672026/10/01 10:24:16 INFO Vacuumed table table=pending_objects30682026/10/01 10:24:16 INFO Vacuumed table table=multipart_uploads30692026/10/01 10:24:16 INFO Vacuumed table table=closures30702026/10/01 10:24:16 INFO Vacuumed table table=objects3071=== NAME TestOrphanedObjectsGCStressTest3072 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains3073--- PASS: TestUploadHandlersRejectOversizedBody (0.26s)3074 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)3075 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)3076 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.76s)3077=== NAME TestOrphanedObjectsGCStressTest3078 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion30792026/10/01 10:24:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=852.837831ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present3080--- PASS: TestPendingClosureWriteTimeout (0.17s)3081 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)3082 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)3083 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)3084 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.15s)3085=== NAME TestOrphanedObjectsGCStressTest3086 orphaned_objects_gc_test.go:509: Stress test completed successfully:3087 orphaned_objects_gc_test.go:510: - Active objects preserved: 203088 orphaned_objects_gc_test.go:511: - Objects deleted: 2103089 orphaned_objects_gc_test.go:512: - Total GC'd: 2103090--- PASS: TestOrphanedObjectsGCStressTest (2.33s)30912026/10/01 10:24:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.64428284s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30922026/10/01 10:24:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03093=== NAME TestClientIntegration3094 client_integration_test.go:323: Objects in database after GC:3095 client_integration_test.go:323: Successfully deleted all objects with GC --force3096--- PASS: TestClientIntegration (2.81s)30972026/10/01 10:24:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=030982026/10/01 10:24:18 INFO Received create pin request method=POST path=/api/pins/myapp30992026/10/01 10:24:18 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1235448722/001/store/3m9k4fql9dyz24kvl6zzv50ygl6a3lg5-pinned-file.txt narinfo_key=3m9k4fql9dyz24kvl6zzv50ygl6a3lg5.narinfo31002026/10/01 10:24:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures31012026/10/01 10:24:18 INFO Garbage collection started31022026/10/01 10:24:18 INFO Aborted multipart uploads count=0 kept=031032026/10/01 10:24:18 WARN Force mode enabled - objects will be deleted immediately without grace period31042026/10/01 10:24:18 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=031052026/10/01 10:24:18 INFO Vacuumed table table=pending_closures31062026/10/01 10:24:18 INFO Vacuumed table table=pending_objects31072026/10/01 10:24:18 INFO Vacuumed table table=multipart_uploads31082026/10/01 10:24:18 INFO Vacuumed table table=closures31092026/10/01 10:24:18 INFO Vacuumed table table=objects3110--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.80s)31112026/10/01 10:24:19 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-config31122026/10/01 10:24:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.882286ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31132026/10/01 10:24:19 WARN Rate limiter enabled after throttle name=s3-test rate=531142026/10/01 10:24:19 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3115=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3116 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103117 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003118--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.99s)31192026/10/01 10:24:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.329738ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31202026/10/01 10:24:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.485611ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3121=== NAME TestPinProtectsFromGC3122 client_integration_test.go:840: Pin successfully protected closure from garbage collection3123--- PASS: TestPinProtectsFromGC (4.59s)31242026/10/01 10:24:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.632890427s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31252026/10/01 10:24:21 INFO Aborted multipart uploads count=1 kept=031262026/10/01 10:24:21 INFO Received cleanup request method=DELETE path=/api/pending_closures31272026/10/01 10:24:21 INFO Aborted multipart uploads count=1 kept=03128--- PASS: TestPendingCleanupUsesOneCutoff (6.69s)31292026/10/01 10:24:22 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"31302026/10/01 10:24:22 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-config31312026/10/01 10:24:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.2164ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31322026/10/01 10:24:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.281619ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31332026/10/01 10:24:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=777.069289ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31342026/10/01 10:24:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.504633058s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31352026/10/01 10:24:25 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_closures31362026/10/01 10:24:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.970345ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31372026/10/01 10:24:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.002513ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31382026/10/01 10:24:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=823.932208ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31392026/10/01 10:24:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.498085408s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3140--- PASS: TestClientErrorHandling (0.00s)3141 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)3142 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)3143 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.54s)3144PASS31452026-10-01 10:24:28.786 UTC [128] LOG: received smart shutdown request31462026-10-01 10:24:28.790 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 131472026-10-01 10:24:28.802 UTC [133] LOG: shutting down31482026-10-01 10:24:28.803 UTC [133] LOG: checkpoint starting: shutdown immediate31492026-10-01 10:24:30.524 UTC [133] LOG: checkpoint complete: wrote 10720 buffers (65.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.282 s, sync=1.382 s, total=1.722 s; sync files=29320, longest=0.003 s, average=0.001 s; distance=405646 kB, estimate=405646 kB; lsn=0/1A389738, redo lsn=0/1A38973831502026-10-01 10:24:30.607 UTC [128] LOG: database system is shut down3151Running OIDC tests...3152=== RUN TestAudienceForIssuer3153=== PAUSE TestAudienceForIssuer3154=== RUN TestGlobMatch3155=== PAUSE TestGlobMatch3156=== RUN TestValidateToken_ValidToken3157=== PAUSE TestValidateToken_ValidToken3158=== RUN TestValidateToken_WrongAudience3159=== PAUSE TestValidateToken_WrongAudience3160=== RUN TestValidateToken_Expired3161=== PAUSE TestValidateToken_Expired3162=== RUN TestValidateToken_BoundClaimsMismatch3163=== PAUSE TestValidateToken_BoundClaimsMismatch3164=== RUN TestValidateToken_BoundSubjectMismatch3165=== PAUSE TestValidateToken_BoundSubjectMismatch3166=== RUN TestValidateToken_MultipleProviders3167=== PAUSE TestValidateToken_MultipleProviders3168=== RUN TestValidateToken_NoMatchingProvider3169=== PAUSE TestValidateToken_NoMatchingProvider3170=== RUN TestValidateToken_KubernetesServiceAccount3171=== PAUSE TestValidateToken_KubernetesServiceAccount3172=== RUN TestNewValidator_KubernetesRequiresCA3173=== PAUSE TestNewValidator_KubernetesRequiresCA3174=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3175=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3176=== RUN TestPins_ReservedForMatchingRule3177=== PAUSE TestPins_ReservedForMatchingRule3178=== RUN TestPins_TopLevelShorthand3179=== PAUSE TestPins_TopLevelShorthand3180=== RUN TestPins_ConfigValidation3181=== PAUSE TestPins_ConfigValidation3182=== RUN TestScopes_LegacyProviderDefaultsToWrite3183=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3184=== RUN TestScopes_Rules3185=== PAUSE TestScopes_Rules3186=== RUN TestScopes_ConfigValidation3187=== PAUSE TestScopes_ConfigValidation3188=== CONT TestAudienceForIssuer3189=== CONT TestValidateToken_KubernetesServiceAccount3190=== CONT TestPins_TopLevelShorthand3191--- PASS: TestAudienceForIssuer (0.00s)3192=== CONT TestValidateToken_NoMatchingProvider3193=== CONT TestValidateToken_MultipleProviders3194=== CONT TestValidateToken_BoundSubjectMismatch3195=== CONT TestValidateToken_BoundClaimsMismatch3196=== CONT TestValidateToken_Expired3197=== CONT TestValidateToken_WrongAudience3198=== CONT TestValidateToken_ValidToken3199=== CONT TestGlobMatch3200=== RUN TestGlobMatch/foo_foo3201=== PAUSE TestGlobMatch/foo_foo3202=== RUN TestGlobMatch/foo_bar3203=== PAUSE TestGlobMatch/foo_bar3204=== RUN TestGlobMatch/*_3205=== PAUSE TestGlobMatch/*_3206=== RUN TestGlobMatch/*_anything3207=== PAUSE TestGlobMatch/*_anything3208=== RUN TestGlobMatch/foo*_foo3209=== PAUSE TestGlobMatch/foo*_foo3210=== RUN TestGlobMatch/foo*_foobar3211=== PAUSE TestGlobMatch/foo*_foobar3212=== RUN TestGlobMatch/foo*_bar3213=== PAUSE TestGlobMatch/foo*_bar3214=== RUN TestGlobMatch/*bar_bar3215=== PAUSE TestGlobMatch/*bar_bar3216=== RUN TestGlobMatch/*bar_foobar3217=== PAUSE TestGlobMatch/*bar_foobar3218=== RUN TestGlobMatch/*bar_foo3219=== PAUSE TestGlobMatch/*bar_foo3220=== RUN TestGlobMatch/foo*bar_foobar3221=== PAUSE TestGlobMatch/foo*bar_foobar3222=== RUN TestGlobMatch/foo*bar_foo123bar3223=== PAUSE TestGlobMatch/foo*bar_foo123bar3224=== RUN TestGlobMatch/foo*bar_foobarbaz3225=== PAUSE TestGlobMatch/foo*bar_foobarbaz3226=== RUN TestGlobMatch/*/*_foo/bar3227=== PAUSE TestGlobMatch/*/*_foo/bar3228=== RUN TestGlobMatch/*/*_foo3229=== PAUSE TestGlobMatch/*/*_foo3230=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3231=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3232=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03233=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03234=== RUN TestGlobMatch/refs/*/main_refs/heads/main3235=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3236=== RUN TestGlobMatch/fo?_foo3237=== PAUSE TestGlobMatch/fo?_foo3238=== RUN TestGlobMatch/fo?_fo3239=== PAUSE TestGlobMatch/fo?_fo3240=== RUN TestGlobMatch/fo?_fooo3241=== PAUSE TestGlobMatch/fo?_fooo3242=== RUN TestGlobMatch/?oo_foo3243=== PAUSE TestGlobMatch/?oo_foo3244=== RUN TestGlobMatch/?oo_boo3245=== PAUSE TestGlobMatch/?oo_boo3246=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3247=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3248=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3249=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3250=== CONT TestGlobMatch/foo_foo3251=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3252=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3253=== CONT TestGlobMatch/?oo_boo3254=== CONT TestGlobMatch/?oo_foo3255=== CONT TestGlobMatch/fo?_fooo3256=== CONT TestGlobMatch/fo?_fo3257=== CONT TestGlobMatch/fo?_foo3258=== CONT TestGlobMatch/refs/*/main_refs/heads/main3259=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03260=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3261=== CONT TestGlobMatch/*/*_foo3262=== CONT TestGlobMatch/*/*_foo/bar3263=== CONT TestGlobMatch/foo*bar_foobarbaz3264=== CONT TestGlobMatch/foo*bar_foo123bar3265=== CONT TestGlobMatch/foo*bar_foobar3266=== CONT TestGlobMatch/*bar_foo3267=== CONT TestGlobMatch/*bar_foobar3268=== CONT TestGlobMatch/*bar_bar3269=== CONT TestGlobMatch/foo*_bar3270=== CONT TestGlobMatch/foo*_foobar3271=== CONT TestGlobMatch/foo*_foo3272=== CONT TestGlobMatch/*_anything3273=== CONT TestGlobMatch/*_3274=== CONT TestGlobMatch/foo_bar3275--- PASS: TestGlobMatch (0.00s)3276 --- PASS: TestGlobMatch/foo_foo (0.00s)3277 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3278 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3279 --- PASS: TestGlobMatch/?oo_boo (0.00s)3280 --- PASS: TestGlobMatch/?oo_foo (0.00s)3281 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3282 --- PASS: TestGlobMatch/fo?_fo (0.00s)3283 --- PASS: TestGlobMatch/fo?_foo (0.00s)3284 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3285 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3286 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3287 --- PASS: TestGlobMatch/*/*_foo (0.00s)3288 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3289 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3290 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3291 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3292 --- PASS: TestGlobMatch/*bar_foo (0.00s)3293 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3294 --- PASS: TestGlobMatch/*bar_bar (0.00s)3295 --- PASS: TestGlobMatch/foo*_bar (0.00s)3296 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3297 --- PASS: TestGlobMatch/foo*_foo (0.00s)3298 --- PASS: TestGlobMatch/*_anything (0.00s)3299 --- PASS: TestGlobMatch/*_ (0.00s)3300 --- PASS: TestGlobMatch/foo_bar (0.00s)3301=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3302=== CONT TestPins_ReservedForMatchingRule3303=== CONT TestNewValidator_KubernetesRequiresCA3304=== CONT TestScopes_LegacyProviderDefaultsToWrite3305=== CONT TestScopes_Rules3306=== CONT TestPins_ConfigValidation3307=== CONT TestScopes_ConfigValidation3308--- PASS: TestPins_ConfigValidation (0.00s)3309--- PASS: TestScopes_ConfigValidation (0.00s)33102026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34809/oidc3311--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)33122026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38491/oidc3313--- PASS: TestValidateToken_Expired (0.03s)33142026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41349/oidc33152026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41713/oidc3316--- PASS: TestValidateToken_ValidToken (0.03s)3317--- PASS: TestScopes_Rules (0.03s)33182026/10/01 10:24:32 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3985733192026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38077/oidc3320--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)3321--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)33222026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38121/oidc33232026/10/01 10:24:32 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34799/oidc3324--- PASS: TestValidateToken_WrongAudience (0.06s)3325--- PASS: TestValidateToken_NoMatchingProvider (0.06s)33262026/10/01 10:24:32 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37223/oidc33272026/10/01 10:24:32 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42635/oidc3328--- PASS: TestValidateToken_MultipleProviders (0.07s)33292026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46155/oidc3330--- PASS: TestPins_ReservedForMatchingRule (0.07s)33312026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34067/oidc3332--- PASS: TestPins_TopLevelShorthand (0.09s)33332026/10/01 10:24:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38681/oidc3334--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)33352026/10/01 10:24:32 http: TLS handshake error from 127.0.0.1:37244: remote error: tls: bad certificate3336--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)33372026/10/01 10:24:32 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233338--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.15s)3339PASS3340Running hook tests...3341=== RUN TestSendPathsEmpty3342=== PAUSE TestSendPathsEmpty3343=== RUN TestQueueEnqueueAndFetch3344=== PAUSE TestQueueEnqueueAndFetch3345=== RUN TestQueueDeduplication3346=== PAUSE TestQueueDeduplication3347=== RUN TestQueueRemove3348=== PAUSE TestQueueRemove3349=== RUN TestQueueFetchBatchLimit3350=== PAUSE TestQueueFetchBatchLimit3351=== RUN TestQueueRetryMovesToBack3352=== PAUSE TestQueueRetryMovesToBack3353=== RUN TestQueueFetchRemoveLifecycle3354=== PAUSE TestQueueFetchRemoveLifecycle3355=== RUN TestQueueConcurrentWriters3356=== PAUSE TestQueueConcurrentWriters3357=== RUN TestQueueRemoveLargeClosure3358=== PAUSE TestQueueRemoveLargeClosure3359=== RUN TestServerClientIntegration3360=== PAUSE TestServerClientIntegration3361=== RUN TestServerQueueError3362=== PAUSE TestServerQueueError3363=== RUN TestGetListenerSocketActivation3364 server_test.go:210: === RUN TestGetListenerSocketActivation3365 --- PASS: TestGetListenerSocketActivation (0.00s)3366 PASS3367 3368--- PASS: TestGetListenerSocketActivation (0.01s)3369=== RUN TestDrainIsolatesPoisonPath3370=== PAUSE TestDrainIsolatesPoisonPath3371=== RUN TestRunNotBlockedByPoisonHead3372=== PAUSE TestRunNotBlockedByPoisonHead3373=== RUN TestDrainGivesUpWhenServerDown3374=== PAUSE TestDrainGivesUpWhenServerDown3375=== RUN TestFailedPathPrunedByLaterClosure3376=== PAUSE TestFailedPathPrunedByLaterClosure3377=== RUN TestWorkerUploadsAndRemoves3378=== PAUSE TestWorkerUploadsAndRemoves3379=== RUN TestWorkerSkipsGCdPaths3380=== PAUSE TestWorkerSkipsGCdPaths3381=== RUN TestWorkerPrunesClosureDeps3382=== PAUSE TestWorkerPrunesClosureDeps3383=== RUN TestDrainTimeout3384=== PAUSE TestDrainTimeout3385=== CONT TestSendPathsEmpty3386=== CONT TestWorkerPrunesClosureDeps3387=== CONT TestQueueRetryMovesToBack3388=== CONT TestDrainTimeout3389=== CONT TestServerClientIntegration3390=== CONT TestQueueRemoveLargeClosure3391=== CONT TestQueueConcurrentWriters3392=== CONT TestQueueFetchRemoveLifecycle3393--- PASS: TestSendPathsEmpty (0.00s)3394=== CONT TestServerQueueError3395=== CONT TestQueueDeduplication33962026/10/01 10:24:32 ERROR Failed to queue paths error="permission denied" count=13397=== CONT TestQueueFetchBatchLimit3398=== CONT TestQueueEnqueueAndFetch3399=== CONT TestFailedPathPrunedByLaterClosure3400=== CONT TestRunNotBlockedByPoisonHead3401=== CONT TestWorkerSkipsGCdPaths3402--- PASS: TestServerClientIntegration (0.00s)3403--- PASS: TestServerQueueError (0.00s)3404=== CONT TestDrainGivesUpWhenServerDown3405=== CONT TestWorkerUploadsAndRemoves3406=== CONT TestDrainIsolatesPoisonPath3407=== CONT TestQueueRemove34082026/10/01 10:24:32 INFO Upload queue status pending=234092026/10/01 10:24:32 INFO Uploading batch count=134102026/10/01 10:24:32 INFO Uploading batch count=234112026/10/01 10:24:32 INFO Uploading batch count=234122026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=234132026/10/01 10:24:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2081328499/002/a34142026/10/01 10:24:32 INFO Uploading batch count=43415--- PASS: TestQueueFetchBatchLimit (0.02s)34162026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=43417--- PASS: TestQueueEnqueueAndFetch (0.02s)34182026/10/01 10:24:32 INFO Upload queue status pending=234192026/10/01 10:24:32 INFO Uploading batch count=134202026/10/01 10:24:32 INFO Upload queue status pending=234212026/10/01 10:24:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2081328499/002/b34222026/10/01 10:24:32 INFO Upload queue status pending=334232026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=134242026/10/01 10:24:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4147132053/002/nonexistent34252026/10/01 10:24:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2530207327/002/bbb34262026/10/01 10:24:32 INFO Uploading batch count=23427--- PASS: TestQueueRetryMovesToBack (0.02s)34282026/10/01 10:24:32 INFO Uploading batch count=134292026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=134302026/10/01 10:24:32 INFO Uploading batch count=23431--- PASS: TestQueueFetchRemoveLifecycle (0.02s)34322026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=234332026/10/01 10:24:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2081328499/002/c34342026/10/01 10:24:32 INFO Uploading batch count=13435--- PASS: TestQueueDeduplication (0.02s)34362026/10/01 10:24:32 INFO Uploading batch count=134372026/10/01 10:24:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2081328499/002/d34382026/10/01 10:24:32 INFO Uploading batch count=134392026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=13440--- PASS: TestQueueRemove (0.02s)34412026/10/01 10:24:32 INFO Uploading batch count=134422026/10/01 10:24:32 INFO Uploading batch count=234432026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=234442026/10/01 10:24:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2081328499/002/e34452026/10/01 10:24:32 INFO Uploading batch count=134462026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=134472026/10/01 10:24:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2081328499/002/f34482026/10/01 10:24:32 INFO Uploading batch count=134492026/10/01 10:24:32 ERROR Upload failed error="upload failed" count=134502026/10/01 10:24:32 ERROR Drain finished with paths left in queue remaining=1034512026/10/01 10:24:32 ERROR Drain finished with paths left in queue remaining=13452--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)3453--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3454--- PASS: TestDrainIsolatesPoisonPath (0.02s)3455--- PASS: TestWorkerSkipsGCdPaths (0.03s)3456--- PASS: TestWorkerUploadsAndRemoves (0.04s)3457--- PASS: TestWorkerPrunesClosureDeps (0.04s)3458--- PASS: TestQueueRemoveLargeClosure (0.12s)34592026/10/01 10:24:32 ERROR Upload failed error="context deadline exceeded" count=234602026/10/01 10:24:32 ERROR Drain finished with paths left in queue remaining=43461--- PASS: TestDrainTimeout (0.22s)3462--- PASS: TestQueueConcurrentWriters (0.58s)34632026/10/01 10:24:33 INFO Uploading batch count=134642026/10/01 10:24:33 INFO Uploading batch count=134652026/10/01 10:24:33 INFO Uploading batch count=134662026/10/01 10:24:33 ERROR Upload failed error="upload failed" count=134672026/10/01 10:24:33 INFO Uploading batch count=134682026/10/01 10:24:33 ERROR Upload failed error="upload failed" count=134692026/10/01 10:24:33 INFO Uploading batch count=134702026/10/01 10:24:33 ERROR Upload failed error="upload failed" count=134712026/10/01 10:24:33 INFO Uploading batch count=134722026/10/01 10:24:33 ERROR Upload failed error="upload failed" count=134732026/10/01 10:24:33 ERROR Drain finished with paths left in queue remaining=13474--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3475PASS