niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #287
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN 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 TestDoWithRetry_BodyReplayedViaGetBody97=== CONT TestScriptTokenBadJSON98=== CONT TestScriptTokenScriptFails99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestDumpPathMatchesNix102=== CONT TestSetClientTLS103=== CONT TestScriptTokenEmptyToken104=== CONT TestScriptTokenCachesUntilRefresh105=== CONT TestScriptTokenNoExpiryRerunsEveryCall106=== CONT TestFileTokenEmpty107--- PASS: TestScriptTokenScriptFails (0.00s)108=== CONT TestConvertHashToNix32109=== RUN TestConvertHashToNix32/SRI_format_to_Nix32110=== CONT TestFilterOversizedClosures111=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32112--- PASS: TestScriptTokenBadJSON (0.00s)113=== CONT TestFileTokenMissing114=== RUN TestFilterOversizedClosures/no_limit_keeps_everything115=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything116=== CONT TestFileTokenReadsAndCaches117=== CONT TestStaticToken1182026/10/01 07:34:01 WARN Rate limiter enabled after throttle name=server-test rate=5119--- PASS: TestStaticToken (0.00s)120=== CONT TestSetClientTLSErrors121=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1222026/10/01 07:34:01 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39927123=== CONT TestEncodeNixBase32WithRealHash124=== CONT TestUploadMultipart_SupersededByPeer125=== CONT TestResolveStorePath126=== CONT TestEncodeNixBase32127=== CONT TestParsePathInfoJSON128=== CONT TestDumpPathWriterError129=== CONT TestPathInfoHashCompatibility130=== CONT TestDumpPathSingleFile131=== CONT TestGetStorePathHash132=== RUN TestConvertHashToNix32/already_Nix32_format133=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped134=== CONT TestStreamPushIsolatesFailures135=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped136=== RUN TestGetStorePathHash/valid_store_path137=== PAUSE TestGetStorePathHash/valid_store_path138=== RUN TestFilterOversizedClosures/all_closures_skipped139=== RUN TestGetStorePathHash/basename_without_hyphen_should_error140=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error141=== CONT TestPartSizeForNAR142=== CONT TestStreamPushRequestLine1432026/10/01 07:34:01 ERROR Upload failed error="bad path" count=3144=== PAUSE TestConvertHashToNix32/already_Nix32_format145=== RUN TestPartSizeForNAR/zero_stays_at_minimum146=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum147=== RUN TestConvertHashToNix32/invalid_format148=== RUN TestPartSizeForNAR/small_stays_at_minimum149=== PAUSE TestPartSizeForNAR/small_stays_at_minimum150=== PAUSE TestFilterOversizedClosures/all_closures_skipped151=== PAUSE TestConvertHashToNix32/invalid_format152--- PASS: TestDoServerRequestAttachesToken (0.01s)153=== CONT TestStreamPushReportsSignatures154--- PASS: TestScriptTokenEmptyToken (0.00s)155=== RUN TestUploadMultipart_SupersededByPeer/exists156=== PAUSE TestUploadMultipart_SupersededByPeer/exists157=== CONT TestRateLimiterFeedback158=== RUN TestUploadMultipart_SupersededByPeer/missing159=== RUN TestEncodeNixBase32/test_string_hash1602026/10/01 07:34:01 ERROR Upload failed error=boom count=1161=== RUN TestRateLimiterFeedback/429_enables_limiter162=== CONT TestUploadMultipart_PartsInParallel163=== RUN TestParsePathInfoJSON/Nix_format164=== CONT TestClientSignaturesByStorePath1652026/10/01 07:34:01 ERROR Upload failed error=boom count=1166=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1672026/10/01 07:34:01 WARN Rate limiter backed off name=server-test rate=5168=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error169=== CONT TestStreamPushGivesUpOnDeadServer1702026/10/01 07:34:01 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39927171=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum172--- PASS: TestEncodeNixBase32WithRealHash (0.00s)173--- PASS: TestFileTokenMissing (0.00s)174=== PAUSE TestUploadMultipart_SupersededByPeer/missing175=== CONT TestPathInfoCACompatibility176=== PAUSE TestEncodeNixBase32/test_string_hash177=== RUN TestPathInfoCACompatibility/null_ca_field178=== RUN TestEncodeNixBase32/empty_input179=== PAUSE TestRateLimiterFeedback/429_enables_limiter180=== PAUSE TestParsePathInfoJSON/Nix_format181--- PASS: TestStreamPushIsolatesFailures (0.00s)182--- PASS: TestFileTokenReadsAndCaches (0.00s)183--- PASS: TestFileTokenEmpty (0.00s)184=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error185--- PASS: TestClientSignaturesByStorePath (0.00s)1862026/10/01 07:34:01 ERROR Upload failed error="connection refused" count=20187--- PASS: TestStreamPushReportsSignatures (0.00s)1882026/10/01 07:34:01 ERROR Server seems unavailable, giving up on batch untried=17189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)190=== CONT TestCaseHackSuffix191=== RUN TestParsePathInfoJSON/Lix_format192=== PAUSE TestParsePathInfoJSON/Lix_format193=== RUN TestParsePathInfoJSON/empty_input194=== CONT TestShellSplitErrors195=== CONT TestRegisterUploadedObjectReusesConnections196=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error197=== CONT TestStreamPushReportsEveryPath198=== RUN TestSetClientTLS/rejects_connection_without_client_cert199=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum200=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess201=== PAUSE TestEncodeNixBase32/empty_input202=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon203=== PAUSE TestPathInfoCACompatibility/null_ca_field204=== RUN TestRateLimiterFeedback/503_enables_limiter205--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)206--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)207--- PASS: TestShellSplitErrors (0.00s)208=== PAUSE TestParsePathInfoJSON/empty_input209=== CONT TestStreamPushBatchesUnderLoad210=== CONT TestShellSplit211=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error212=== CONT TestFilterOversizedClosures/no_limit_keeps_everything213=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert214=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA215=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA216=== RUN TestSetClientTLS/preserves_debug_logging_transport2172026/10/01 07:34:01 WARN Rate limiter enabled after throttle name=server-test rate=5218=== PAUSE TestSetClientTLS/preserves_debug_logging_transport219=== CONT TestParsePathInfoJSONMultiplePaths220--- PASS: TestStreamPushReportsEveryPath (0.00s)221--- PASS: TestResolveStorePath (0.04s)222=== RUN TestSetClientTLSErrors/missing_cert_file223=== CONT TestConvertHashToNix32/SRI_format_to_Nix32224=== PAUSE TestSetClientTLSErrors/missing_cert_file225=== RUN TestSetClientTLSErrors/missing_key_file226=== PAUSE TestSetClientTLSErrors/missing_key_file227=== RUN TestSetClientTLSErrors/missing_ca_file228=== PAUSE TestSetClientTLSErrors/missing_ca_file229=== RUN TestSetClientTLSErrors/invalid_ca_file230=== PAUSE TestSetClientTLSErrors/invalid_ca_file231=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths232=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths233=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths234=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths235=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon236=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI237=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI238=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512239=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512240=== RUN TestPathInfoCACompatibility/old_string_format_-_text241=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text242=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive243=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive244=== RUN TestPathInfoCACompatibility/new_structured_format_-_text245=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text246=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method247=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method248=== RUN TestParsePathInfoJSON/whitespace_only249=== PAUSE TestParsePathInfoJSON/whitespace_only250=== CONT TestGetStorePathHash/valid_store_path251=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error252=== CONT TestGetStorePathHash/basename_without_hyphen_should_error253=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error254=== CONT TestSetClientTLS/rejects_connection_without_client_cert255--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.04s)256=== RUN TestParsePathInfoJSON/invalid_JSON257=== PAUSE TestParsePathInfoJSON/invalid_JSON258=== CONT TestFilterOversizedClosures/all_closures_skipped2592026/10/01 07:34:01 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=50260=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA261=== CONT TestSetClientTLS/preserves_debug_logging_transport262--- PASS: TestGetStorePathHash (0.04s)263 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)264 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)265 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)266 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)267=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped268=== CONT TestUploadMultipart_SupersededByPeer/exists2692026/10/01 07:34:01 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=2000270--- PASS: TestFilterOversizedClosures (0.00s)271 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)272 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)273 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)274=== CONT TestUploadMultipart_SupersededByPeer/missing275=== CONT TestSetClientTLSErrors/missing_cert_file276=== CONT TestConvertHashToNix32/already_Nix32_format277=== CONT TestEncodeNixBase32/test_string_hash278=== CONT TestConvertHashToNix32/invalid_format279=== CONT TestEncodeNixBase32/empty_input280=== PAUSE TestRateLimiterFeedback/503_enables_limiter281=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths282--- PASS: TestShellSplit (0.00s)283=== CONT TestPathInfoCACompatibility/null_ca_field284=== CONT TestSetClientTLSErrors/invalid_ca_file285=== CONT TestSetClientTLSErrors/missing_ca_file286=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts287=== CONT TestSetClientTLSErrors/missing_key_file288=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths289--- PASS: TestEncodeNixBase32 (0.01s)290 --- PASS: TestEncodeNixBase32/empty_input (0.00s)291 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)292--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)293--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)294 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)295 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)296=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method297--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)298=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive299--- PASS: TestConvertHashToNix32 (0.00s)300 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)301 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)302 --- PASS: TestConvertHashToNix32/invalid_format (0.01s)303=== CONT TestPathInfoCACompatibility/new_structured_format_-_text304=== CONT TestPathInfoCACompatibility/old_string_format_-_text305--- PASS: TestPathInfoCACompatibility (0.04s)306 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)307 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)308 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)309 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)310 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)311=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts312=== RUN TestPartSizeForNAR/1_TiB313=== PAUSE TestPartSizeForNAR/1_TiB314=== RUN TestPartSizeForNAR/5_TiB_S3_max_object315=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object316=== RUN TestPartSizeForNAR/capped_at_5_GiB317=== PAUSE TestPartSizeForNAR/capped_at_5_GiB318=== CONT TestPartSizeForNAR/zero_stays_at_minimum319--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)320 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)321 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)322=== CONT TestParsePathInfoJSON/whitespace_only323=== CONT TestPartSizeForNAR/1_TiB324=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts325=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum326=== CONT TestPartSizeForNAR/small_stays_at_minimum327=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon328=== CONT TestParsePathInfoJSON/Nix_format329=== CONT TestParsePathInfoJSON/empty_input330=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter331=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter332=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter333=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter334=== CONT TestRateLimiterFeedback/429_enables_limiter335--- PASS: TestSetClientTLSErrors (0.04s)336 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)337 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)338 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)339 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)340=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512341=== CONT TestParsePathInfoJSON/invalid_JSON342=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI343=== CONT TestParsePathInfoJSON/Lix_format344=== CONT TestRateLimiterFeedback/503_enables_limiter345=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)346--- PASS: TestPathInfoHashCompatibility (0.04s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)348 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)349 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)350 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)351=== CONT TestPartSizeForNAR/5_TiB_S3_max_object3522026/10/01 07:34:01 WARN Rate limiter enabled after throttle name=server-test rate=5353--- PASS: TestParsePathInfoJSON (0.04s)354 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)355 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)356 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)357 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)358 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3592026/10/01 07:34:01 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:40683360=== CONT TestPartSizeForNAR/capped_at_5_GiB361--- PASS: TestPartSizeForNAR (0.06s)362 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)364 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)365 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)368 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)369=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter370=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3712026/10/01 07:34:01 WARN Rate limiter enabled after throttle name=server-test rate=53722026/10/01 07:34:01 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:438353732026/10/01 07:34:01 WARN Rate limiter backed off name=server-test rate=53742026/10/01 07:34:01 WARN Rate limiter backed off name=server-test rate=5375--- PASS: TestRateLimiterFeedback (0.06s)376 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)3802026/10/01 07:34:01 http: TLS handshake error from 127.0.0.1:37180: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.04s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)385--- PASS: TestDumpPathWriterError (0.07s)386--- PASS: TestDumpPathSingleFile (0.07s)387--- PASS: TestCaseHackSuffix (0.07s)388--- PASS: TestStreamPushRequestLine (0.08s)389--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)390--- PASS: TestDumpPathMatchesNix (0.12s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres2624064031/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/postgres2624064031/data -l logfile start422423/build/postgres2624064031:5432 - no response4242026-10-01 07:34:03.424 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 07:34:03.425 UTC [129] LOG: listening on Unix socket "/build/postgres2624064031/.s.PGSQL.5432"4262026-10-01 07:34:03.429 UTC [136] LOG: database system was shut down at 2026-10-01 07:34:03 UTC4272026-10-01 07:34:03.433 UTC [129] LOG: database system is ready to accept connections428/build/postgres2624064031:5432 - accepting connections429{"timestamp":"2026-10-01T07:34:03.624400313Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"66a7bb0f-5a12-4db1-a3f8-b4a281870ff5","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(209)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 07:34:03.813 UTC [374] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 07:34:03.813 UTC [374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 07:34:03 OK 20241026095416_initial_model.sql (11.36ms)4742026/10/01 07:34:03 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)4752026/10/01 07:34:03 OK 20251218171726_add_pins.sql (3.62ms)4762026/10/01 07:34:03 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)4772026/10/01 07:34:03 OK 20260905000000_add_claims.sql (3.66ms)4782026/10/01 07:34:03 OK 20260920000000_drop_claims.sql (2.39ms)4792026/10/01 07:34:03 OK 20260923120000_add_pushes.sql (7.23ms)4802026/10/01 07:34:03 goose: successfully migrated database to version: 202609231200004812026/10/01 07:34:03 OK 1_commit_pending_closure.sql (1.94ms)4822026/10/01 07:34:03 OK 2_object_stats_trigger.sql (908.75µs)4832026/10/01 07:34:03 OK 3_commit_push.sql (606.15µs)4842026/10/01 07:34:03 goose: up to current file version: 34852026/10/01 07:34:03 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 07:34:04 INFO lead: released remote=192.0.2.1:12344872026/10/01 07:34:04 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 07:34:04 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 07:34:04.590 UTC [384] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 07:34:04.590 UTC [384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 07:34:04 OK 20241026095416_initial_model.sql (9.11ms)4962026/10/01 07:34:04 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)4972026/10/01 07:34:04 OK 20251218171726_add_pins.sql (3.27ms)4982026/10/01 07:34:04 OK 20260628120000_add_object_size_and_stats.sql (2.99ms)4992026/10/01 07:34:04 OK 20260905000000_add_claims.sql (2.7ms)5002026/10/01 07:34:04 OK 20260920000000_drop_claims.sql (1.64ms)5012026/10/01 07:34:04 OK 20260923120000_add_pushes.sql (1.24ms)5022026/10/01 07:34:04 goose: successfully migrated database to version: 202609231200005032026/10/01 07:34:04 OK 1_commit_pending_closure.sql (1.72ms)5042026/10/01 07:34:04 OK 2_object_stats_trigger.sql (737.49µs)5052026/10/01 07:34:04 OK 3_commit_push.sql (545.7µs)5062026/10/01 07:34:04 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestGCTaskStore_StartNew533=== PAUSE TestGCTaskStore_StartNew534=== RUN TestGCTaskStore_DeduplicateSameParams535=== PAUSE TestGCTaskStore_DeduplicateSameParams536=== RUN TestGCTaskStore_ConflictDifferentParams537=== PAUSE TestGCTaskStore_ConflictDifferentParams538=== RUN TestGCTaskStore_GetEmpty539=== PAUSE TestGCTaskStore_GetEmpty540=== RUN TestGCTaskStore_GetReturnsLatest541=== PAUSE TestGCTaskStore_GetReturnsLatest542=== RUN TestGCTaskStore_CompletedAllowsNewTask543=== PAUSE TestGCTaskStore_CompletedAllowsNewTask544=== RUN TestGCTaskStore_PhaseUpdates545=== PAUSE TestGCTaskStore_PhaseUpdates546=== RUN TestGCTaskStore_Fail547=== PAUSE TestGCTaskStore_Fail548=== RUN TestGracefulShutdownDrainsInflight549=== PAUSE TestGracefulShutdownDrainsInflight550=== RUN TestService_healthCheckHandler551=== PAUSE TestService_healthCheckHandler552=== RUN TestService_readinessHandler553=== PAUSE TestService_readinessHandler554=== RUN TestGenerateLandingPage555=== PAUSE TestGenerateLandingPage556=== RUN TestCacheConfigHandlerMaxNarSize557=== PAUSE TestCacheConfigHandlerMaxNarSize558=== RUN TestCreatePendingClosureRejectsOversizedNAR559=== PAUSE TestCreatePendingClosureRejectsOversizedNAR560=== RUN TestNARDeduplicationMetadataUploadBug561=== PAUSE TestNARDeduplicationMetadataUploadBug562=== RUN TestMetricsInventory563=== PAUSE TestMetricsInventory564=== RUN TestService_NativeMTLS565=== PAUSE TestService_NativeMTLS566=== RUN TestServerTLSConfig567=== PAUSE TestServerTLSConfig568=== RUN TestMultipartCleanup569=== PAUSE TestMultipartCleanup570=== RUN TestObjectStatsTrigger571=== PAUSE TestObjectStatsTrigger572=== RUN TestOrphanedObjectsGC573=== PAUSE TestOrphanedObjectsGC574=== RUN TestOrphanedObjectsGCStressTest575=== PAUSE TestOrphanedObjectsGCStressTest576=== RUN TestCreatePin_ReservedPins577=== PAUSE TestCreatePin_ReservedPins578=== RUN TestParseSingleRange579=== PAUSE TestParseSingleRange580=== RUN TestProxyHeadersOnlyTrustedOnSocket581=== PAUSE TestProxyHeadersOnlyTrustedOnSocket582=== RUN TestIsValidCachePath583=== PAUSE TestIsValidCachePath584=== RUN TestReadProxyNarinfo585=== PAUSE TestReadProxyNarinfo586=== RUN TestReadProxyNarinfoAlreadyDecompressed587=== PAUSE TestReadProxyNarinfoAlreadyDecompressed588=== RUN TestReadProxyNarStreaming589=== PAUSE TestReadProxyNarStreaming590=== RUN TestReadProxy404591=== PAUSE TestReadProxy404592=== RUN TestReadProxyInvalidPath593=== PAUSE TestReadProxyInvalidPath594=== RUN TestReadProxyHead595=== PAUSE TestReadProxyHead596=== RUN TestReadProxyConditionalGet597=== PAUSE TestReadProxyConditionalGet598=== RUN TestReadProxyRootRedirectsToIndexHTML599=== PAUSE TestReadProxyRootRedirectsToIndexHTML600=== RUN TestReadProxyDisabled601=== PAUSE TestReadProxyDisabled602=== RUN TestReadRedirectNar603=== PAUSE TestReadRedirectNar604=== RUN TestReadRedirectKeepsNarinfoProxied605=== PAUSE TestReadRedirectKeepsNarinfoProxied606=== RUN TestReadProxyRangeRequest607=== PAUSE TestReadProxyRangeRequest608=== RUN TestReadRedirectUsesPublicS3URL609=== PAUSE TestReadRedirectUsesPublicS3URL610=== RUN TestPush_OverlappingRootsStoreOneRowPerKey611=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey612=== RUN TestPush_CompleteCommitsEveryRoot613=== PAUSE TestPush_CompleteCommitsEveryRoot614=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit615=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit616=== RUN TestPush_RejectsBadRequests617=== PAUSE TestPush_RejectsBadRequests618=== RUN TestPush_SignsNarinfosOfItsPendingObjects619=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects620=== RUN TestRedundantMultipartUpload621=== PAUSE TestRedundantMultipartUpload622=== RUN TestCompleteMultipartUpload_ErrorButObjectExists623=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists624=== RUN TestCompletedNarNotReofferedAcrossClosures625=== PAUSE TestCompletedNarNotReofferedAcrossClosures626=== RUN TestPresignedUploadRegisteredBeforeCommit627=== PAUSE TestPresignedUploadRegisteredBeforeCommit628=== RUN TestService_Rustfstest629=== PAUSE TestService_Rustfstest630=== RUN TestParseSize631=== PAUSE TestParseSize632=== RUN TestSkippedUploadsHandler633=== PAUSE TestSkippedUploadsHandler634=== RUN TestSystemdListenerNotActivated635--- PASS: TestSystemdListenerNotActivated (0.00s)636=== RUN TestWatchdogBeatsWhenHealthy637--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)638=== RUN TestWatchdogSkipsWhenUnhealthy6392026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 07:34:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"648--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)649=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle650=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle651=== RUN TestProxyWriteTimeout652=== PAUSE TestProxyWriteTimeout653=== RUN TestIsValidUploadKey654=== PAUSE TestIsValidUploadKey655=== RUN TestUploadHandlersRejectInvalidKeys656=== PAUSE TestUploadHandlersRejectInvalidKeys657=== RUN TestUploadHandlersRejectOversizedBody658=== PAUSE TestUploadHandlersRejectOversizedBody659=== RUN TestService_cleanupPendingClosuresHandler660=== PAUSE TestService_cleanupPendingClosuresHandler661=== RUN TestService_createPendingClosureHandler662=== PAUSE TestService_createPendingClosureHandler663=== RUN TestService_verifyS3Integrity664=== PAUSE TestService_verifyS3Integrity665=== RUN TestCompleteMultipartUnregistered666=== PAUSE TestCompleteMultipartUnregistered667=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT668=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT669=== CONT TestSkippedUploadsHandler670=== CONT TestGCTaskStore_GetEmpty671=== CONT TestGCTaskStore_GetReturnsLatest672=== CONT TestPushDedupSurvivesConcurrentGC673=== CONT TestService_AuthMiddleware674--- PASS: TestGCTaskStore_GetEmpty (0.00s)675--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)676=== CONT TestParseSize677--- PASS: TestParseSize (0.00s)678=== CONT TestGCMetrics679=== CONT TestService_Rustfstest6802026/10/01 07:34:04 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000681=== CONT TestPresignedUploadRegisteredBeforeCommit682=== CONT TestCompletedNarNotReofferedAcrossClosures683=== CONT TestCompleteMultipartUpload_ErrorButObjectExists684=== CONT TestRedundantMultipartUpload685=== CONT TestPush_SignsNarinfosOfItsPendingObjects686=== CONT TestPush_RejectsBadRequests687=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit688=== CONT TestGCTaskStore_ConflictDifferentParams689--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)690=== CONT TestGCTaskStore_DeduplicateSameParams691=== CONT TestGCTaskStore_StartNew692=== CONT TestGetExistingObjectsLocksRows693=== CONT TestRegisterCompletedObjectNeedsPendingRow694=== CONT TestSweepSkipsRowsLockedByPush695=== CONT TestFailedS3DeleteKeepsTombstone696=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection697=== CONT TestGCSweepDeliversEachKeyOnce698=== CONT TestTombstonedObjectOfferedWithoutWaiting699=== CONT TestGCSweepSkipsPendingObjects700=== CONT TestDeduplicatedObjectsRecordedAsPending701=== CONT TestGCBugBareHashReferences702--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)703=== CONT TestLeadEndsOnShutdown704--- PASS: TestGCTaskStore_StartNew (0.00s)705=== CONT TestLeadElectsOneAndHandsOver706--- PASS: TestSkippedUploadsHandler (0.00s)707=== CONT TestResolveDBConnectionString708=== RUN TestResolveDBConnectionString/flag_wins709=== PAUSE TestResolveDBConnectionString/flag_wins710=== RUN TestResolveDBConnectionString/file_when_flag_empty711=== PAUSE TestResolveDBConnectionString/file_when_flag_empty712=== RUN TestResolveDBConnectionString/missing_file_is_an_error713=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error714=== RUN TestResolveDBConnectionString/PGHOST_allows_empty715=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty716=== RUN TestResolveDBConnectionString/nothing_configured717=== PAUSE TestResolveDBConnectionString/nothing_configured718=== CONT TestClientFallsBackToClosures7192026-10-01 07:34:05.018 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367202026-10-01 07:34:05.018 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7212026-10-01 07:34:05.020 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367222026-10-01 07:34:05.020 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026-10-01 07:34:05.020 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367242026-10-01 07:34:05.020 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7252026-10-01 07:34:05.022 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367262026-10-01 07:34:05.022 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7272026-10-01 07:34:05.065 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367282026-10-01 07:34:05.065 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7292026-10-01 07:34:05.066 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367302026-10-01 07:34:05.066 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7312026-10-01 07:34:05.066 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367322026-10-01 07:34:05.066 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7332026-10-01 07:34:05.069 UTC [462] ERROR: relation "goose_db_version" does not exist at character 367342026-10-01 07:34:05.069 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7352026/10/01 07:34:05 OK 20241026095416_initial_model.sql (31.99ms)7362026/10/01 07:34:05 OK 20241026095416_initial_model.sql (41.61ms)7372026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (8.37ms)7382026/10/01 07:34:05 OK 20241026095416_initial_model.sql (42.86ms)7392026-10-01 07:34:05.100 UTC [463] ERROR: relation "goose_db_version" does not exist at character 367402026-10-01 07:34:05.100 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7412026/10/01 07:34:05 OK 20241026095416_initial_model.sql (44.68ms)7422026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)7432026-10-01 07:34:05.106 UTC [464] ERROR: relation "goose_db_version" does not exist at character 367442026-10-01 07:34:05.106 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7452026-10-01 07:34:05.108 UTC [465] ERROR: relation "goose_db_version" does not exist at character 367462026-10-01 07:34:05.108 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7472026/10/01 07:34:05 OK 20251218171726_add_pins.sql (8.54ms)7482026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (4.91ms)7492026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (6.28ms)7502026-10-01 07:34:05.110 UTC [466] ERROR: relation "goose_db_version" does not exist at character 367512026-10-01 07:34:05.110 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7522026/10/01 07:34:05 OK 20251218171726_add_pins.sql (12.95ms)7532026/10/01 07:34:05 OK 20251218171726_add_pins.sql (5.13ms)7542026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (6ms)7552026/10/01 07:34:05 OK 20251218171726_add_pins.sql (5.68ms)7562026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (15.14ms)7572026/10/01 07:34:05 OK 20260905000000_add_claims.sql (16.77ms)7582026/10/01 07:34:05 OK 20241026095416_initial_model.sql (33.07ms)7592026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (18.62ms)7602026/10/01 07:34:05 OK 20241026095416_initial_model.sql (33.91ms)7612026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (18.75ms)7622026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.58ms)7632026/10/01 07:34:05 OK 20260905000000_add_claims.sql (5.68ms)7642026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)7652026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (3.48ms)7662026/10/01 07:34:05 OK 20241026095416_initial_model.sql (31.62ms)7672026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3ms)7682026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200007692026/10/01 07:34:05 OK 20260905000000_add_claims.sql (5.49ms)7702026/10/01 07:34:05 OK 20241026095416_initial_model.sql (34.91ms)7712026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.7ms)7722026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (4.18ms)7732026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (3.33ms)7742026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)7752026/10/01 07:34:05 OK 20251218171726_add_pins.sql (5.46ms)7762026/10/01 07:34:05 OK 1_commit_pending_closure.sql (3.38ms)7772026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.51ms)7782026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.24ms)7792026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200007802026/10/01 07:34:05 OK 20241026095416_initial_model.sql (27.12ms)7812026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.6ms)7822026/10/01 07:34:05 OK 20251218171726_add_pins.sql (6.32ms)7832026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.9ms)7842026/10/01 07:34:05 OK 20241026095416_initial_model.sql (28.93ms)7852026/10/01 07:34:05 OK 20241026095416_initial_model.sql (12.79ms)7862026/10/01 07:34:05 OK 3_commit_push.sql (1.52ms)7872026/10/01 07:34:05 goose: up to current file version: 37882026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.83ms)7892026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200007902026/10/01 07:34:05 OK 20251218171726_add_pins.sql (5.05ms)7912026/10/01 07:34:05 OK 20241026095416_initial_model.sql (28.84ms)7922026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.63ms)7932026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.67ms)7942026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)7952026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200007962026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.82ms)7972026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5ms)7982026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)7992026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)8002026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)8012026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.08ms)8022026/10/01 07:34:05 OK 1_commit_pending_closure.sql (3.35ms)8032026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.84ms)8042026/10/01 07:34:05 OK 3_commit_push.sql (1.05ms)8052026/10/01 07:34:05 goose: up to current file version: 38062026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.65ms)8072026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)8082026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.41ms)8092026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.59ms)8102026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.76ms)8112026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.79ms)8122026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)8132026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.79ms)8142026/10/01 07:34:05 OK 3_commit_push.sql (1.15ms)8152026/10/01 07:34:05 goose: up to current file version: 38162026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.25ms)8172026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.63ms)8182026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.88ms)8192026-10-01 07:34:05.154 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368202026-10-01 07:34:05.154 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026-10-01 07:34:05.155 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368222026-10-01 07:34:05.155 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026-10-01 07:34:05.155 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368242026-10-01 07:34:05.155 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8252026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.52ms)8262026-10-01 07:34:05.155 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368272026-10-01 07:34:05.155 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026/10/01 07:34:05 OK 3_commit_push.sql (1.95ms)8292026/10/01 07:34:05 goose: up to current file version: 38302026-10-01 07:34:05.156 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368312026-10-01 07:34:05.156 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026-10-01 07:34:05.156 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368332026-10-01 07:34:05.156 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8342026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.76ms)8352026-10-01 07:34:05.156 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368362026-10-01 07:34:05.156 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)8382026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.66ms)8392026/10/01 07:34:05 OK 20260905000000_add_claims.sql (5.68ms)8402026-10-01 07:34:05.157 UTC [475] ERROR: relation "goose_db_version" does not exist at character 368412026-10-01 07:34:05.157 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.92ms)8432026-10-01 07:34:05.158 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368442026-10-01 07:34:05.158 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8452026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.84ms)8462026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008472026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)8482026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (4.19ms)8492026-10-01 07:34:05.158 UTC [476] ERROR: relation "goose_db_version" does not exist at character 368502026-10-01 07:34:05.158 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8512026-10-01 07:34:05.159 UTC [477] ERROR: relation "goose_db_version" does not exist at character 368522026-10-01 07:34:05.159 UTC [477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8532026-10-01 07:34:05.160 UTC [478] ERROR: relation "goose_db_version" does not exist at character 368542026-10-01 07:34:05.160 UTC [478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8552026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.41ms)8562026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.84ms)8572026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.16ms)8582026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.23ms)8592026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008602026/10/01 07:34:05 OK 1_commit_pending_closure.sql (3.59ms)8612026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.26ms)8622026/10/01 07:34:05 OK 20260905000000_add_claims.sql (5.11ms)8632026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.49ms)8642026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008652026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.37ms)8662026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.36ms)8672026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008682026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.27ms)8692026/10/01 07:34:05 OK 2_object_stats_trigger.sql (3.38ms)8702026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (4.8ms)8712026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.64ms)8722026/10/01 07:34:05 OK 1_commit_pending_closure.sql (4.37ms)8732026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures8742026/10/01 07:34:05 OK 1_commit_pending_closure.sql (5.06ms)8752026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (5.43ms)8762026/10/01 07:34:05 OK 3_commit_push.sql (2.11ms)8772026/10/01 07:34:05 goose: up to current file version: 38782026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.88ms)8792026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008802026/10/01 07:34:05 OK 1_commit_pending_closure.sql (4.32ms)8812026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.72ms)8822026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.28ms)8832026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008842026/10/01 07:34:05 OK 2_object_stats_trigger.sql (3.45ms)8852026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (5.4ms)8862026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008872026/10/01 07:34:05 OK 1_commit_pending_closure.sql (3.88ms)8882026/10/01 07:34:05 OK 3_commit_push.sql (2.54ms)8892026/10/01 07:34:05 goose: up to current file version: 38902026/10/01 07:34:05 OK 2_object_stats_trigger.sql (3.38ms)8912026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (6.13ms)8922026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200008932026/10/01 07:34:05 OK 3_commit_push.sql (1.58ms)8942026/10/01 07:34:05 goose: up to current file version: 38952026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.3ms)8962026/10/01 07:34:05 OK 3_commit_push.sql (1.95ms)8972026/10/01 07:34:05 goose: up to current file version: 38982026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.05ms)8992026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.76ms)9002026/10/01 07:34:05 OK 3_commit_push.sql (1.35ms)9012026/10/01 07:34:05 goose: up to current file version: 39022026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.86ms)9032026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.2ms)9042026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.44ms)9052026/10/01 07:34:05 OK 20241026095416_initial_model.sql (14.42ms)9062026/10/01 07:34:05 OK 20241026095416_initial_model.sql (15.12ms)9072026/10/01 07:34:05 OK 3_commit_push.sql (1.66ms)9082026/10/01 07:34:05 goose: up to current file version: 39092026/10/01 07:34:05 OK 20241026095416_initial_model.sql (14.15ms)9102026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.27ms)9112026/10/01 07:34:05 OK 3_commit_push.sql (2.16ms)9122026/10/01 07:34:05 goose: up to current file version: 39132026/10/01 07:34:05 OK 20241026095416_initial_model.sql (14.86ms)9142026/10/01 07:34:05 OK 3_commit_push.sql (1.38ms)9152026/10/01 07:34:05 goose: up to current file version: 39162026/10/01 07:34:05 OK 20241026095416_initial_model.sql (15.32ms)9172026/10/01 07:34:05 OK 20241026095416_initial_model.sql (12.64ms)9182026/10/01 07:34:05 OK 20241026095416_initial_model.sql (15.35ms)9192026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)9202026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)9212026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)9222026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)9232026/10/01 07:34:05 OK 20241026095416_initial_model.sql (14.77ms)9242026/10/01 07:34:05 OK 20241026095416_initial_model.sql (17.06ms)9252026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)9262026/10/01 07:34:05 OK 20241026095416_initial_model.sql (13.43ms)9272026/10/01 07:34:05 OK 20241026095416_initial_model.sql (17.92ms)9282026/10/01 07:34:05 OK 20241026095416_initial_model.sql (15.56ms)9292026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)9302026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)9312026/10/01 07:34:05 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9322026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures9332026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.68ms)9342026/10/01 07:34:05 OK 20251218171726_add_pins.sql (2.94ms)9352026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.69ms)9362026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)9372026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)9382026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)9392026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.61ms)9402026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.08ms)9412026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.51ms)942--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.32s)9432026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)944=== CONT TestClientPushesUseOnePush9452026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)9462026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.65ms)9472026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures9482026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)9492026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.97ms)9502026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)9512026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.75ms)9522026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.29ms)9532026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.2ms)9542026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)9552026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.75ms)9562026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)9572026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.53ms)9582026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.6ms)9592026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.47ms)9602026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)9612026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.52ms)9622026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.99ms)9632026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)9642026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)9652026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)9662026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.27ms)9672026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.91ms)9682026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.2ms)9692026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)9702026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)9712026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.76ms)9722026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.47ms)9732026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.02ms)9742026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.87ms)9752026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.46ms)9762026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200009772026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.1ms)9782026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.69ms)9792026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (1.67ms)9802026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200009812026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.28ms)9822026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.97ms)9832026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.73ms)9842026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.43ms)9852026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.79ms)9862026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.01ms)9872026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.1ms)9882026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200009892026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.96ms)9902026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.55ms)9912026/10/01 07:34:05 OK 20260905000000_add_claims.sql (6.23ms)9922026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200009932026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.54ms)9942026/10/01 07:34:05 goose: successfully migrated database to version: 202609231200009952026/10/01 07:34:05 OK 1_commit_pending_closure.sql (3.64ms)9962026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.9ms)9972026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (4.57ms)9982026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (4.22ms)9992026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.76ms)10002026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.78ms)10012026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.76ms)10022026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000010032026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000010042026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.97ms)10052026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.64ms)10062026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (1.95ms)10072026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000010082026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.24ms)10092026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.1ms)10102026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000010112026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.75ms)10122026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.18ms)10132026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.16ms)10142026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.38ms)10152026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.83ms)10162026/10/01 07:34:05 OK 3_commit_push.sql (1.79ms)10172026/10/01 07:34:05 goose: up to current file version: 310182026/10/01 07:34:05 OK 3_commit_push.sql (2.04ms)10192026/10/01 07:34:05 goose: up to current file version: 310202026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.05ms)10212026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.21ms)10222026/10/01 07:34:05 OK 3_commit_push.sql (1.4ms)10232026/10/01 07:34:05 goose: up to current file version: 310242026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.22ms)10252026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.26ms)10262026/10/01 07:34:05 OK 3_commit_push.sql (1.51ms)10272026/10/01 07:34:05 goose: up to current file version: 310282026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (4.17ms)10292026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000010302026/10/01 07:34:05 OK 3_commit_push.sql (1.3ms)10312026/10/01 07:34:05 goose: up to current file version: 310322026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.82ms)10332026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.81ms)10342026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.07ms)10352026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.41ms)10362026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000010372026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.43ms)10382026/10/01 07:34:05 OK 3_commit_push.sql (1.66ms)10392026/10/01 07:34:05 goose: up to current file version: 310402026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.52ms)10412026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.56ms)10422026/10/01 07:34:05 OK 3_commit_push.sql (1.77ms)10432026/10/01 07:34:05 goose: up to current file version: 310442026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (3.23ms)10452026/10/01 07:34:05 OK 1_commit_pending_closure.sql (1.83ms)10462026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000010472026/10/01 07:34:05 OK 3_commit_push.sql (964.81µs)10482026/10/01 07:34:05 goose: up to current file version: 310492026/10/01 07:34:05 OK 3_commit_push.sql (606.19µs)10502026/10/01 07:34:05 goose: up to current file version: 310512026/10/01 07:34:05 OK 2_object_stats_trigger.sql (791.57µs)10522026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.14ms)10532026/10/01 07:34:05 OK 3_commit_push.sql (563.91µs)10542026/10/01 07:34:05 goose: up to current file version: 310552026/10/01 07:34:05 OK 1_commit_pending_closure.sql (1.58ms)10562026/10/01 07:34:05 OK 3_commit_push.sql (716.03µs)10572026/10/01 07:34:05 goose: up to current file version: 310582026/10/01 07:34:05 INFO Aborted multipart uploads count=010592026/10/01 07:34:05 OK 2_object_stats_trigger.sql (720.39µs)10602026/10/01 07:34:05 OK 3_commit_push.sql (454.96µs)10612026/10/01 07:34:05 goose: up to current file version: 310622026/10/01 07:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period10632026/10/01 07:34:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010642026/10/01 07:34:05 INFO Vacuumed table table=pending_closures10652026/10/01 07:34:05 INFO Vacuumed table table=pending_objects10662026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads10672026/10/01 07:34:05 INFO Vacuumed table table=closures10682026/10/01 07:34:05 INFO Vacuumed table table=objects10692026/10/01 07:34:05 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1070--- PASS: TestService_AuthMiddleware (0.35s)1071=== CONT TestService_cleanupPendingClosuresHandler1072--- PASS: TestGCMetrics (0.35s)1073=== CONT TestPinProtectsFromGC10742026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures10752026/10/01 07:34:05 INFO Received push request method=POST path=/api/pushes10762026/10/01 07:34:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10772026/10/01 07:34:05 INFO Signed narinfos id=1 count=11078--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.40s)1079=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT10802026/10/01 07:34:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10812026-10-01 07:34:05.275 UTC [488] ERROR: relation "goose_db_version" does not exist at character 3610822026-10-01 07:34:05.275 UTC [488] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10832026/10/01 07:34:05 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjkwZmFjNjMtY2RjYy00NGY3LTgwOWItNmM0MDE3NGNjNWI1LjdlYmMyZTFhLTAyN2EtNDkzMS1iZmVmLTM2OTM5MzBhYmFhYXgxNzkwODQwMDQ1MjUyNzczMDU210842026/10/01 07:34:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjkwZmFjNjMtY2RjYy00NGY3LTgwOWItNmM0MDE3NGNjNWI1LjdlYmMyZTFhLTAyN2EtNDkzMS1iZmVmLTM2OTM5MzBhYmFhYXgxNzkwODQwMDQ1MjUyNzczMDU2 parts=11085--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.42s)1086=== CONT TestClientSharedPathCommittedMidPush10872026/10/01 07:34:05 OK 20241026095416_initial_model.sql (9.38ms)10882026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)10892026/10/01 07:34:05 OK 20251218171726_add_pins.sql (2.98ms)10902026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures1091--- PASS: TestService_Rustfstest (0.43s)1092=== CONT TestCompleteMultipartUnregistered10932026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)10942026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.08ms)10952026-10-01 07:34:05.304 UTC [493] ERROR: relation "goose_db_version" does not exist at character 3610962026-10-01 07:34:05.304 UTC [493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10972026-10-01 07:34:05.307 UTC [495] ERROR: relation "goose_db_version" does not exist at character 3610982026-10-01 07:34:05.307 UTC [495] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10992026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.95ms)11002026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.24ms)11012026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000011022026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.32ms)11032026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.32ms)11042026/10/01 07:34:05 OK 3_commit_push.sql (1.75ms)11052026/10/01 07:34:05 goose: up to current file version: 311062026/10/01 07:34:05 OK 20241026095416_initial_model.sql (10ms)11072026/10/01 07:34:05 OK 20241026095416_initial_model.sql (11.47ms)11082026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)11092026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)11102026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.81ms)11112026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.65ms)11122026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (10.62ms)11132026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (11.18ms)11142026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.01ms)11152026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.23ms)11162026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.14ms)11172026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.99ms)11182026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.39ms)11192026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000011202026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.55ms)11212026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000011222026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.09ms)11232026-10-01 07:34:05.353 UTC [497] ERROR: relation "goose_db_version" does not exist at character 3611242026-10-01 07:34:05.353 UTC [497] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11252026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.31ms)11262026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.37ms)11272026/10/01 07:34:05 INFO Aborted multipart uploads count=011282026/10/01 07:34:05 OK 3_commit_push.sql (1.51ms)11292026/10/01 07:34:05 goose: up to current file version: 311302026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.62ms)11312026/10/01 07:34:05 OK 3_commit_push.sql (1.18ms)11322026/10/01 07:34:05 goose: up to current file version: 311332026/10/01 07:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period11342026/10/01 07:34:05 INFO Aborted multipart uploads count=011352026-10-01 07:34:05.363 UTC [501] ERROR: relation "goose_db_version" does not exist at character 3611362026-10-01 07:34:05.363 UTC [501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11372026/10/01 07:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period11382026/10/01 07:34:05 INFO Aborted multipart uploads count=011392026/10/01 07:34:05 OK 20241026095416_initial_model.sql (9.42ms)11402026/10/01 07:34:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011412026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)11422026/10/01 07:34:05 INFO Vacuumed table table=pending_closures11432026/10/01 07:34:05 INFO Vacuumed table table=pending_objects11442026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads11452026/10/01 07:34:05 INFO Vacuumed table table=closures11462026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.17ms)11472026/10/01 07:34:05 INFO Vacuumed table table=objects11482026/10/01 07:34:05 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=011492026/10/01 07:34:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011502026/10/01 07:34:05 INFO Vacuumed table table=pending_closures11512026/10/01 07:34:05 INFO Vacuumed table table=pending_objects11522026-10-01 07:34:05.375 UTC [503] ERROR: relation "goose_db_version" does not exist at character 3611532026-10-01 07:34:05.375 UTC [503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11542026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads11552026/10/01 07:34:05 INFO Vacuumed table table=closures11562026/10/01 07:34:05 INFO Vacuumed table table=pending_closures11572026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)11582026/10/01 07:34:05 INFO Vacuumed table table=pending_objects11592026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads11602026/10/01 07:34:05 INFO Vacuumed table table=objects11612026/10/01 07:34:05 INFO Aborted multipart uploads count=01162--- PASS: TestGCSweepDeliversEachKeyOnce (0.51s)1163=== CONT TestClientWithDependencies11642026/10/01 07:34:05 OK 20241026095416_initial_model.sql (10.06ms)11652026/10/01 07:34:05 INFO Vacuumed table table=closures11662026/10/01 07:34:05 OK 20260905000000_add_claims.sql (2.64ms)11672026/10/01 07:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period11682026/10/01 07:34:05 INFO Vacuumed table table=objects11692026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (1.9ms)11702026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)11712026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.38ms)11722026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000011732026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures11742026/10/01 07:34:05 OK 20251218171726_add_pins.sql (2.24ms)11752026/10/01 07:34:05 INFO Aborted multipart uploads count=011762026/10/01 07:34:05 OK 1_commit_pending_closure.sql (1.63ms)11772026/10/01 07:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period11782026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.14ms)11792026/10/01 07:34:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011802026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (2.61ms)11812026/10/01 07:34:05 OK 3_commit_push.sql (774.07µs)11822026/10/01 07:34:05 goose: up to current file version: 311832026/10/01 07:34:05 INFO Vacuumed table table=pending_closures11842026/10/01 07:34:05 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=011852026/10/01 07:34:05 INFO Vacuumed table table=pending_closures11862026/10/01 07:34:05 INFO Vacuumed table table=pending_objects11872026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads11882026/10/01 07:34:05 INFO Vacuumed table table=closures11892026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.29ms)11902026/10/01 07:34:05 OK 20241026095416_initial_model.sql (10.86ms)11912026/10/01 07:34:05 INFO Vacuumed table table=pending_objects11922026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads11932026/10/01 07:34:05 INFO Vacuumed table table=objects11942026/10/01 07:34:05 INFO Vacuumed table table=closures11952026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2ms)1196--- PASS: TestSweepSkipsRowsLockedByPush (0.52s)1197=== CONT TestService_verifyS3Integrity11982026/10/01 07:34:05 INFO Vacuumed table table=objects1199--- PASS: TestPushDedupSurvivesConcurrentGC (0.53s)1200=== CONT TestClientMultipleUploads12012026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.8ms)12022026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000012032026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)12042026/10/01 07:34:05 OK 1_commit_pending_closure.sql (1.98ms)12052026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.59ms)12062026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.36ms)12072026/10/01 07:34:05 OK 3_commit_push.sql (1.57ms)12082026/10/01 07:34:05 goose: up to current file version: 312092026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures12102026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)12112026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.74ms)12122026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.48ms)12132026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.38ms)12142026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000012152026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures12162026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.3ms)12172026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.45ms)12182026/10/01 07:34:05 OK 3_commit_push.sql (1.2ms)12192026/10/01 07:34:05 goose: up to current file version: 312202026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/01 07:34:05 INFO Received push request method=POST path=/api/pushes12222026/10/01 07:34:05 INFO Aborted multipart uploads count=012232026/10/01 07:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period12242026/10/01 07:34:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012252026-10-01 07:34:05.454 UTC [511] ERROR: relation "goose_db_version" does not exist at character 3612262026-10-01 07:34:05.454 UTC [511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12272026/10/01 07:34:05 INFO Vacuumed table table=pending_closures12282026/10/01 07:34:05 INFO Vacuumed table table=pending_objects12292026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads12302026/10/01 07:34:05 INFO Vacuumed table table=closures12312026/10/01 07:34:05 INFO Vacuumed table table=objects12322026/10/01 07:34:05 INFO lead: acquired remote=192.0.2.1:123412332026/10/01 07:34:05 INFO lead: released remote=192.0.2.1:123412342026/10/01 07:34:05 INFO Received complete push request method=POST path=/api/pushes/1/complete1235--- PASS: TestLeadEndsOnShutdown (0.59s)1236=== CONT TestService_createPendingClosureHandler1237--- PASS: TestGCSweepSkipsPendingObjects (0.59s)1238=== CONT TestClientIntegration12392026/10/01 07:34:05 OK 20241026095416_initial_model.sql (7.58ms)12402026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)12412026-10-01 07:34:05.471 UTC [513] ERROR: relation "goose_db_version" does not exist at character 3612422026-10-01 07:34:05.471 UTC [513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12432026/10/01 07:34:05 OK 20251218171726_add_pins.sql (2.55ms)12442026-10-01 07:34:05.472 UTC [514] ERROR: relation "goose_db_version" does not exist at character 3612452026-10-01 07:34:05.472 UTC [514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026/10/01 07:34:05 INFO Received push request method=POST path=/api/pushes12472026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)12482026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.96ms)12492026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.26ms)12502026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.42ms)12512026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000012522026/10/01 07:34:05 OK 20241026095416_initial_model.sql (9.17ms)12532026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.54ms)12542026/10/01 07:34:05 OK 20241026095416_initial_model.sql (10.27ms)12552026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)12562026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.46ms)12572026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)12582026/10/01 07:34:05 OK 3_commit_push.sql (1.14ms)12592026/10/01 07:34:05 goose: up to current file version: 312602026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures12612026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.5ms)12622026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.52ms)12632026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)12642026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)1265--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.62s)1266=== CONT TestClientErrorHandling1267=== RUN TestClientErrorHandling/InvalidStorePath1268=== PAUSE TestClientErrorHandling/InvalidStorePath1269=== RUN TestClientErrorHandling/InvalidAuthToken1270=== PAUSE TestClientErrorHandling/InvalidAuthToken1271=== RUN TestClientErrorHandling/ServerNotAvailable1272=== PAUSE TestClientErrorHandling/ServerNotAvailable1273=== CONT TestParseSingleRange1274=== RUN TestParseSingleRange/none1275=== PAUSE TestParseSingleRange/none1276=== RUN TestParseSingleRange/unknown_unit1277=== PAUSE TestParseSingleRange/unknown_unit1278=== RUN TestParseSingleRange/multi-range_ignored1279=== PAUSE TestParseSingleRange/multi-range_ignored1280=== RUN TestParseSingleRange/malformed_no_dash1281=== PAUSE TestParseSingleRange/malformed_no_dash1282=== RUN TestParseSingleRange/malformed_both_empty1283=== PAUSE TestParseSingleRange/malformed_both_empty1284=== RUN TestParseSingleRange/malformed_end_before_start1285=== PAUSE TestParseSingleRange/malformed_end_before_start1286=== RUN TestParseSingleRange/closed1287=== PAUSE TestParseSingleRange/closed1288=== RUN TestParseSingleRange/open-ended1289=== PAUSE TestParseSingleRange/open-ended1290=== RUN TestParseSingleRange/end_clamped_to_size1291=== PAUSE TestParseSingleRange/end_clamped_to_size1292=== RUN TestParseSingleRange/suffix1293=== PAUSE TestParseSingleRange/suffix1294=== RUN TestParseSingleRange/suffix_exceeds_size1295=== PAUSE TestParseSingleRange/suffix_exceeds_size1296=== RUN TestParseSingleRange/single_byte1297=== PAUSE TestParseSingleRange/single_byte1298=== RUN TestParseSingleRange/start_past_EOF1299=== PAUSE TestParseSingleRange/start_past_EOF1300=== RUN TestParseSingleRange/start_far_past_EOF1301=== PAUSE TestParseSingleRange/start_far_past_EOF1302=== CONT TestClientCADerivations13032026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.07ms)13042026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.18ms)13052026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.46ms)13062026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (1.45ms)13072026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000013082026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.04ms)13092026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.18ms)13102026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.26ms)13112026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000013122026/10/01 07:34:05 OK 2_object_stats_trigger.sql (701.67µs)13132026/10/01 07:34:05 OK 3_commit_push.sql (1.03ms)13142026/10/01 07:34:05 goose: up to current file version: 313152026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.09ms)13162026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.17ms)13172026/10/01 07:34:05 OK 3_commit_push.sql (1.02ms)13182026/10/01 07:34:05 goose: up to current file version: 31319--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.64s)1320=== CONT TestPush_CompleteCommitsEveryRoot13212026/10/01 07:34:05 INFO lead: acquired remote=192.0.2.1:123413222026/10/01 07:34:05 INFO Aborted multipart uploads count=013232026/10/01 07:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period13242026-10-01 07:34:05.543 UTC [524] ERROR: relation "goose_db_version" does not exist at character 3613252026-10-01 07:34:05.543 UTC [524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13262026-10-01 07:34:05.543 UTC [525] ERROR: relation "goose_db_version" does not exist at character 3613272026-10-01 07:34:05.543 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13282026/10/01 07:34:05 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=013292026/10/01 07:34:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13302026/10/01 07:34:05 INFO Vacuumed table table=pending_closures13312026/10/01 07:34:05 INFO Vacuumed table table=pending_objects13322026/10/01 07:34:05 INFO Vacuumed table table=multipart_uploads13332026/10/01 07:34:05 INFO Vacuumed table table=closures13342026/10/01 07:34:05 INFO Vacuumed table table=objects13352026/10/01 07:34:05 INFO Received complete push request method=POST path=/api/pushes/2/complete13362026/10/01 07:34:05 OK 20241026095416_initial_model.sql (12.57ms)13372026/10/01 07:34:05 OK 20241026095416_initial_model.sql (12.65ms)13382026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)13392026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)1340--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.70s)1341=== CONT TestCacheStatsHandler13422026/10/01 07:34:05 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjkwZmFjNjMtY2RjYy00NGY3LTgwOWItNmM0MDE3NGNjNWI1LjEwOGRmYTAyLTA2YjgtNGRiNy1hYjM0LWUxODAxNDM0NDU5OHgxNzkwODQwMDQ1MTk0OTkyMjc5 parts=1213432026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.92ms)13442026/10/01 07:34:05 OK 20251218171726_add_pins.sql (3.55ms)13452026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures13462026-10-01 07:34:05.575 UTC [548] ERROR: relation "goose_db_version" does not exist at character 3613472026-10-01 07:34:05.575 UTC [548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13482026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)13492026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)1350--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.71s)1351=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13522026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.1ms)13532026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.29ms)13542026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.99ms)1355--- PASS: TestGCBugBareHashReferences (0.71s)1356=== CONT TestCacheConfigHandler1357=== RUN TestCacheConfigHandler/full_config,_no_issuer1358=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1359=== RUN TestCacheConfigHandler/no_cache_url_configured1360=== PAUSE TestCacheConfigHandler/no_cache_url_configured1361=== RUN TestCacheConfigHandler/no_signing_keys1362=== PAUSE TestCacheConfigHandler/no_signing_keys1363=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1364=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1365=== CONT TestReadRedirectUsesPublicS3URL13662026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.26ms)13672026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.16ms)13682026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000013692026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.04ms)13702026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000013712026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.5ms)13722026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.44ms)13732026/10/01 07:34:05 OK 2_object_stats_trigger.sql (729.49µs)13742026/10/01 07:34:05 OK 2_object_stats_trigger.sql (929.81µs)1375--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.72s)13762026/10/01 07:34:05 OK 3_commit_push.sql (676.55µs)1377=== CONT TestService_ReadScope_PublicByDefault13782026/10/01 07:34:05 goose: up to current file version: 313792026/10/01 07:34:05 OK 3_commit_push.sql (886.11µs)13802026/10/01 07:34:05 goose: up to current file version: 313812026-10-01 07:34:05.589 UTC [552] ERROR: relation "goose_db_version" does not exist at character 3613822026-10-01 07:34:05.589 UTC [552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1383--- PASS: TestGetExistingObjectsLocksRows (0.72s)1384=== CONT TestReadProxyRangeRequest13852026/10/01 07:34:05 OK 20241026095416_initial_model.sql (16.26ms)13862026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)13872026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.95ms)13882026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures13892026/10/01 07:34:05 OK 20241026095416_initial_model.sql (12.4ms)13902026/10/01 07:34:05 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)13912026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.81ms)1392--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.74s)1393=== CONT TestService_RequireScope_OIDC13942026/10/01 07:34:05 OK 20251218171726_add_pins.sql (4.15ms)13952026/10/01 07:34:05 OK 20260905000000_add_claims.sql (4.59ms)13962026/10/01 07:34:05 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)13972026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (3.75ms)13982026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (2.87ms)13992026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000014002026/10/01 07:34:05 OK 20260905000000_add_claims.sql (3.85ms)1401=== RUN TestPush_RejectsBadRequests/no_roots1402=== PAUSE TestPush_RejectsBadRequests/no_roots1403=== RUN TestPush_RejectsBadRequests/no_objects1404=== PAUSE TestPush_RejectsBadRequests/no_objects1405=== RUN TestPush_RejectsBadRequests/bad_root1406=== PAUSE TestPush_RejectsBadRequests/bad_root1407=== RUN TestPush_RejectsBadRequests/root_not_in_objects1408=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1409=== CONT TestReadRedirectKeepsNarinfoProxied14102026/10/01 07:34:05 OK 20260920000000_drop_claims.sql (2.8ms)14112026/10/01 07:34:05 OK 1_commit_pending_closure.sql (9.61ms)14122026/10/01 07:34:05 OK 20260923120000_add_pushes.sql (7.77ms)14132026/10/01 07:34:05 goose: successfully migrated database to version: 2026092312000014142026/10/01 07:34:05 OK 2_object_stats_trigger.sql (2.54ms)14152026/10/01 07:34:05 OK 3_commit_push.sql (1.41ms)14162026/10/01 07:34:05 goose: up to current file version: 314172026/10/01 07:34:05 OK 1_commit_pending_closure.sql (2.78ms)14182026/10/01 07:34:05 OK 2_object_stats_trigger.sql (1.57ms)14192026/10/01 07:34:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43983/oidc14202026/10/01 07:34:05 OK 3_commit_push.sql (2.41ms)14212026/10/01 07:34:05 goose: up to current file version: 314222026/10/01 07:34:05 INFO Received uploads request method=POST path=/api/pending_closures14232026-10-01 07:34:05.651 UTC [598] ERROR: relation "goose_db_version" does not exist at character 3614242026-10-01 07:34:05.651 UTC [598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14252026/10/01 07:34:05 INFO lead: released remote=192.0.2.1:123414262026/10/01 07:34:05 INFO lead: acquired remote=192.0.2.1:123414272026/10/01 07:34:05 ERROR lead error="context canceled"14282026/10/01 07:34:05 INFO lead: released remote=192.0.2.1:12341429--- PASS: TestLeadElectsOneAndHandsOver (1.10s)1430=== CONT TestService_AuthMiddleware_OIDC14312026-10-01 07:34:05.980 UTC [617] ERROR: relation "goose_db_version" does not exist at character 3614322026-10-01 07:34:05.980 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14332026-10-01 07:34:05.995 UTC [618] ERROR: relation "goose_db_version" does not exist at character 3614342026-10-01 07:34:05.995 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14352026-10-01 07:34:06.004 UTC [621] ERROR: relation "goose_db_version" does not exist at character 3614362026-10-01 07:34:06.004 UTC [621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026-10-01 07:34:06.004 UTC [620] ERROR: relation "goose_db_version" does not exist at character 3614382026-10-01 07:34:06.004 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026/10/01 07:34:06 OK 20241026095416_initial_model.sql (20.7ms)14402026/10/01 07:34:06 OK 20241026095416_initial_model.sql (20.93ms)14412026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.79ms)14422026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)14432026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)14442026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)14452026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.61ms)14462026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.43ms)14472026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.78ms)14482026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)14492026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)14502026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.87ms)14512026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.64ms)14522026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)14532026/10/01 07:34:06 OK 20241026095416_initial_model.sql (11.65ms)14542026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)14552026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.07ms)14562026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)14572026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.7ms)14582026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.77ms)14592026/10/01 07:34:06 INFO Received cleanup request method=DELETE path=/api/pending_closures14602026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.73ms)14612026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.86ms)14622026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.8ms)14632026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000014642026/10/01 07:34:06 OK 20251218171726_add_pins.sql (5.07ms)14652026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (4.35ms)14662026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000014672026/10/01 07:34:06 INFO Aborted multipart uploads count=014682026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.85ms)14692026-10-01 07:34:06.037 UTC [640] ERROR: relation "goose_db_version" does not exist at character 3614702026-10-01 07:34:06.037 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14712026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.53ms)14722026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.46ms)14732026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures14742026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)14752026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.79ms)14762026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000014772026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.09ms)14782026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)14792026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.34ms)14802026/10/01 07:34:06 OK 3_commit_push.sql (1.04ms)14812026/10/01 07:34:06 goose: up to current file version: 314822026/10/01 07:34:06 OK 3_commit_push.sql (1.02ms)14832026/10/01 07:34:06 goose: up to current file version: 314842026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.99ms)14852026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.48ms)14862026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.68ms)14872026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.11ms)14882026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.17ms)14892026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.49ms)14902026/10/01 07:34:06 OK 3_commit_push.sql (1.32ms)14912026/10/01 07:34:06 goose: up to current file version: 314922026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.78ms)14932026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000014942026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.65ms)14952026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000014962026/10/01 07:34:06 INFO Received cleanup request method=DELETE path=/api/pending_closures14972026/10/01 07:34:06 OK 1_commit_pending_closure.sql (1.82ms)14982026-10-01 07:34:06.050 UTC [658] ERROR: relation "goose_db_version" does not exist at character 3614992026-10-01 07:34:06.050 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15002026/10/01 07:34:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41253/oidc15012026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.69ms)15022026/10/01 07:34:06 INFO Aborted multipart uploads count=115032026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.53ms)15042026/10/01 07:34:06 OK 2_object_stats_trigger.sql (801.65µs)15052026/10/01 07:34:06 OK 3_commit_push.sql (593.49µs)15062026/10/01 07:34:06 goose: up to current file version: 315072026/10/01 07:34:06 INFO Aborted multipart uploads count=015082026/10/01 07:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15092026-10-01 07:34:06.053 UTC [493] ERROR: Closure does not exist: id=115102026-10-01 07:34:06.053 UTC [493] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE15112026-10-01 07:34:06.053 UTC [493] STATEMENT: -- name: CommitPendingClosure :exec1512 SELECT commit_pending_closure($1::bigint)1513 1514--- PASS: TestService_cleanupPendingClosuresHandler (0.83s)1515=== CONT TestReadRedirectNar15162026/10/01 07:34:06 OK 3_commit_push.sql (1.13ms)15172026/10/01 07:34:06 goose: up to current file version: 315182026/10/01 07:34:06 OK 20241026095416_initial_model.sql (9.7ms)15192026/10/01 07:34:06 WARN Force mode enabled - objects will be deleted immediately without grace period15202026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)15212026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.18ms)15222026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)15232026/10/01 07:34:06 OK 20241026095416_initial_model.sql (8.15ms)15242026/10/01 07:34:06 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."15252026/10/01 07:34:06 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15262026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)1527--- PASS: TestFailedS3DeleteKeepsTombstone (1.19s)1528=== CONT TestService_ReadAuthMiddleware15292026/10/01 07:34:06 OK 20260905000000_add_claims.sql (14.73ms)15302026/10/01 07:34:06 OK 20251218171726_add_pins.sql (15.11ms)15312026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.37ms)15322026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures15332026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.62ms)15342026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000015352026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)15362026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.34ms)15372026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.92ms)15382026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.48ms)15392026/10/01 07:34:06 OK 3_commit_push.sql (1.6ms)15402026/10/01 07:34:06 goose: up to current file version: 315412026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures15422026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.95ms)15432026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures15442026/10/01 07:34:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15452026/10/01 07:34:06 INFO Uploading f3vikaxi62l84ggmvdz9xxfhnyd7fqba-b (216B)15462026/10/01 07:34:06 INFO Uploading 4pz14fjrahr34da7xl2lnirgs1fcq0lr-shared-dep (136B)15472026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.19ms)15482026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000015492026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.61ms)15502026/10/01 07:34:06 WARN Failed to register uploaded object key=ncbc9iy8wir0bgbngfdydcna95z61zyg.ls error="server returned 404: 404 page not found\n"15512026/10/01 07:34:06 OK 2_object_stats_trigger.sql (2.63ms)15522026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/0irszf76d2dfgx42ba47gi2yinh8bff3s2zwp3m9djr6i6vja4zx.nar.zst error="server returned 404: 404 page not found\n"15532026/10/01 07:34:06 WARN Failed to register uploaded object key=f3vikaxi62l84ggmvdz9xxfhnyd7fqba.ls error="server returned 404: 404 page not found\n"15542026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15552026/10/01 07:34:06 WARN Failed to register uploaded object key=4pz14fjrahr34da7xl2lnirgs1fcq0lr.ls error="server returned 404: 404 page not found\n"15562026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15572026/10/01 07:34:06 INFO Signed narinfos id=1 count=215582026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15592026/10/01 07:34:06 OK 3_commit_push.sql (1.77ms)15602026/10/01 07:34:06 goose: up to current file version: 315612026/10/01 07:34:06 INFO Signed narinfos id=2 count=215622026/10/01 07:34:06 INFO Uploading 4 narinfos1563--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.83s)1564=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15652026/10/01 07:34:06 WARN Failed to register uploaded object key=f3vikaxi62l84ggmvdz9xxfhnyd7fqba.narinfo error="server returned 404: 404 page not found\n"15662026/10/01 07:34:06 WARN Failed to register uploaded object key=ncbc9iy8wir0bgbngfdydcna95z61zyg.narinfo error="server returned 404: 404 page not found\n"15672026/10/01 07:34:06 WARN Failed to register uploaded object key=4pz14fjrahr34da7xl2lnirgs1fcq0lr.narinfo error="server returned 404: 404 page not found\n"15682026/10/01 07:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15692026/10/01 07:34:06 WARN Failed to register uploaded object key=4pz14fjrahr34da7xl2lnirgs1fcq0lr.narinfo error="server returned 404: 404 page not found\n"15702026/10/01 07:34:06 INFO Completed upload id=115712026/10/01 07:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15722026/10/01 07:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15732026/10/01 07:34:06 INFO Completed upload id=215742026/10/01 07:34:06 INFO Upload complete. (87ms)1575=== NAME TestClientFallsBackToClosures1576 client_pushes_test.go:112: Retrieved narinfo from S3:1577 StorePath: /build/TestClientFallsBackToClosures1880892752/001/store/4pz14fjrahr34da7xl2lnirgs1fcq0lr-shared-dep1578 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1579 Compression: zstd1580 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821581 NarSize: 1361582 References: 1583 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1584 client_pushes_test.go:112: Retrieved narinfo from S3:1585 StorePath: /build/TestClientFallsBackToClosures1880892752/001/store/ncbc9iy8wir0bgbngfdydcna95z61zyg-a1586 URL: nar/0irszf76d2dfgx42ba47gi2yinh8bff3s2zwp3m9djr6i6vja4zx.nar.zst1587 Compression: zstd1588 NarHash: sha256:0irszf76d2dfgx42ba47gi2yinh8bff3s2zwp3m9djr6i6vja4zx1589 NarSize: 2161590 References: /build/TestClientFallsBackToClosures1880892752/001/store/4pz14fjrahr34da7xl2lnirgs1fcq0lr-shared-dep1591 CA: text:sha256:03v4k990fdxz8x0m8in1gzyaibxip4qlw7yv2bg30xrwx29bdzaq1592 client_pushes_test.go:112: Retrieved narinfo from S3:1593 StorePath: /build/TestClientFallsBackToClosures1880892752/001/store/f3vikaxi62l84ggmvdz9xxfhnyd7fqba-b1594 URL: nar/0irszf76d2dfgx42ba47gi2yinh8bff3s2zwp3m9djr6i6vja4zx.nar.zst1595 Compression: zstd1596 NarHash: sha256:0irszf76d2dfgx42ba47gi2yinh8bff3s2zwp3m9djr6i6vja4zx1597 NarSize: 2161598 References: /build/TestClientFallsBackToClosures1880892752/001/store/4pz14fjrahr34da7xl2lnirgs1fcq0lr-shared-dep1599 CA: text:sha256:03v4k990fdxz8x0m8in1gzyaibxip4qlw7yv2bg30xrwx29bdzaq1600=== NAME TestPinProtectsFromGC1601 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3182914843/001/store/vkaxakb3ibzidvh7190vcdwrzq4sazkw-pinned-file.txt1602 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3182914843/001/store/5hlql1vd13q43rnnk5qhwzpcpz5i2gqp-unpinned-file.txt1603--- PASS: TestClientFallsBackToClosures (1.26s)1604=== CONT TestService_AuthMiddleware_MTLSProxyHeader16052026/10/01 07:34:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjkwZmFjNjMtY2RjYy00NGY3LTgwOWItNmM0MDE3NGNjNWI1LjI1ZDY2OGVjLTk3ZjAtNDM0MC1iNTc1LWFkMWE0MWFjNWRkYXgxNzkwODQwMDQ1NDEwNjM0ODc2 parts=121606--- PASS: TestRedundantMultipartUpload (1.27s)1607=== CONT TestReadProxyDisabled16082026-10-01 07:34:06.140 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3616092026-10-01 07:34:06.140 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16102026/10/01 07:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16112026-10-01 07:34:06.140 UTC [759] ERROR: relation "goose_db_version" does not exist at character 3616122026-10-01 07:34:06.140 UTC [759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16132026/10/01 07:34:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1614--- PASS: TestCompleteMultipartUnregistered (0.84s)1615=== CONT TestReadProxy40416162026-10-01 07:34:06.154 UTC [764] ERROR: relation "goose_db_version" does not exist at character 3616172026-10-01 07:34:06.154 UTC [764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16182026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.45ms)16192026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)16202026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.08ms)16212026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)16222026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.34ms)16232026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.85ms)16242026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)16252026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)16262026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.98ms)16272026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.44ms)16282026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)16292026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.37ms)16302026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.6ms)16312026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.38ms)16322026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000016332026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.79ms)16342026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.46ms)16352026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.55ms)16362026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.41ms)16372026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000016382026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)16392026/10/01 07:34:06 OK 2_object_stats_trigger.sql (2.1ms)16402026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.18ms)16412026/10/01 07:34:06 OK 3_commit_push.sql (1.3ms)16422026/10/01 07:34:06 goose: up to current file version: 316432026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.26ms)16442026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.51ms)16452026/10/01 07:34:06 OK 3_commit_push.sql (1.57ms)16462026/10/01 07:34:06 goose: up to current file version: 316472026-10-01 07:34:06.187 UTC [820] ERROR: relation "goose_db_version" does not exist at character 3616482026-10-01 07:34:06.187 UTC [820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16492026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.49ms)16502026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures16512026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.48ms)16522026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000016532026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.57ms)16542026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes16552026/10/01 07:34:06 OK 2_object_stats_trigger.sql (8.33ms)16562026/10/01 07:34:06 OK 3_commit_push.sql (1.34ms)16572026/10/01 07:34:06 goose: up to current file version: 316582026/10/01 07:34:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16592026/10/01 07:34:06 INFO Uploading vg8iz3xwx1y7nyb6z4n251wxlln208k5-shared-dep (136B)16602026/10/01 07:34:06 INFO Uploading yv0b14zdpggncv3dirk8k3yzmdmmlaa6-b (208B)16612026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes16622026/10/01 07:34:06 WARN Failed to register uploaded object key=cvn9j123sy22nxsrbnpcd2bdzydi4qzg.ls error="server returned 404: 404 page not found\n"16632026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16642026/10/01 07:34:06 WARN Failed to register uploaded object key=yv0b14zdpggncv3dirk8k3yzmdmmlaa6.ls error="server returned 404: 404 page not found\n"16652026/10/01 07:34:06 WARN Failed to register uploaded object key=vg8iz3xwx1y7nyb6z4n251wxlln208k5.ls error="server returned 404: 404 page not found\n"16662026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16672026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/0g0mfvws1k4j3kakvyff0h14b074612687i3l0bhzjfg68lhj78b.nar.zst error="server returned 404: 404 page not found\n"16682026/10/01 07:34:06 INFO Signed narinfos id=1 count=316692026/10/01 07:34:06 INFO Uploading 3 narinfos16702026/10/01 07:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16712026/10/01 07:34:06 INFO Uploading vkaxakb3ibzidvh7190vcdwrzq4sazkw-pinned-file.txt (128B)16722026/10/01 07:34:06 OK 20241026095416_initial_model.sql (11ms)16732026-10-01 07:34:06.213 UTC [889] ERROR: relation "goose_db_version" does not exist at character 3616742026-10-01 07:34:06.213 UTC [889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16752026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)16762026/10/01 07:34:06 WARN Failed to register uploaded object key=cvn9j123sy22nxsrbnpcd2bdzydi4qzg.narinfo error="server returned 404: 404 page not found\n"16772026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete16782026/10/01 07:34:06 WARN Failed to register uploaded object key=vg8iz3xwx1y7nyb6z4n251wxlln208k5.narinfo error="server returned 404: 404 page not found\n"16792026/10/01 07:34:06 WARN Failed to register uploaded object key=yv0b14zdpggncv3dirk8k3yzmdmmlaa6.narinfo error="server returned 404: 404 page not found\n"16802026/10/01 07:34:06 WARN Failed to register uploaded object key=vkaxakb3ibzidvh7190vcdwrzq4sazkw.ls error="server returned 404: 404 page not found\n"16812026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16822026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16832026/10/01 07:34:06 INFO Signed narinfos id=1 count=116842026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.48ms)16852026/10/01 07:34:06 INFO Uploading 1 narinfos16862026-10-01 07:34:06.219 UTC [891] ERROR: relation "goose_db_version" does not exist at character 3616872026-10-01 07:34:06.219 UTC [891] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16882026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)16892026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete16902026/10/01 07:34:06 WARN Failed to register uploaded object key=vkaxakb3ibzidvh7190vcdwrzq4sazkw.narinfo error="server returned 404: 404 page not found\n"16912026/10/01 07:34:06 INFO Upload complete. (62ms)16922026-10-01 07:34:06.223 UTC [893] ERROR: relation "goose_db_version" does not exist at character 3616932026-10-01 07:34:06.223 UTC [893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1694=== NAME TestClientPushesUseOnePush1695 client_pushes_test.go:97: Retrieved narinfo from S3:1696 StorePath: /build/TestClientPushesUseOnePush956624847/001/store/vg8iz3xwx1y7nyb6z4n251wxlln208k5-shared-dep1697 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1698 Compression: zstd1699 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821700 NarSize: 1361701 References: 1702 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17032026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.51ms)1704 client_pushes_test.go:97: Retrieved narinfo from S3:1705 StorePath: /build/TestClientPushesUseOnePush956624847/001/store/cvn9j123sy22nxsrbnpcd2bdzydi4qzg-a1706 URL: nar/0g0mfvws1k4j3kakvyff0h14b074612687i3l0bhzjfg68lhj78b.nar.zst1707 Compression: zstd1708 NarHash: sha256:0g0mfvws1k4j3kakvyff0h14b074612687i3l0bhzjfg68lhj78b1709 NarSize: 2081710 References: /build/TestClientPushesUseOnePush956624847/001/store/vg8iz3xwx1y7nyb6z4n251wxlln208k5-shared-dep1711 CA: text:sha256:0np4ksz7ghmcj0g1mgy1yzi14y0vvi8gq58z0wmf9vcvnp414jxg17122026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (1.76ms)17132026/10/01 07:34:06 INFO Upload complete. (61ms)17142026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.36ms)17152026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.24ms)17162026/10/01 07:34:06 goose: successfully migrated database to version: 202609231200001717 client_pushes_test.go:97: Retrieved narinfo from S3:1718 StorePath: /build/TestClientPushesUseOnePush956624847/001/store/yv0b14zdpggncv3dirk8k3yzmdmmlaa6-b1719 URL: nar/0g0mfvws1k4j3kakvyff0h14b074612687i3l0bhzjfg68lhj78b.nar.zst1720 Compression: zstd1721 NarHash: sha256:0g0mfvws1k4j3kakvyff0h14b074612687i3l0bhzjfg68lhj78b1722 NarSize: 2081723 References: /build/TestClientPushesUseOnePush956624847/001/store/vg8iz3xwx1y7nyb6z4n251wxlln208k5-shared-dep1724 CA: text:sha256:0np4ksz7ghmcj0g1mgy1yzi14y0vvi8gq58z0wmf9vcvnp414jxg17252026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)17262026/10/01 07:34:06 OK 1_commit_pending_closure.sql (1.51ms)17272026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.06ms)17282026/10/01 07:34:06 OK 3_commit_push.sql (1.04ms)1729--- PASS: TestClientPushesUseOnePush (1.05s)17302026/10/01 07:34:06 goose: up to current file version: 31731=== CONT TestReadProxyNarStreaming17322026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures17332026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures17342026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures17352026/10/01 07:34:06 OK 20251218171726_add_pins.sql (2.59ms)17362026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.1ms)17372026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)17382026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)17392026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.36ms)17402026/10/01 07:34:06 OK 20260905000000_add_claims.sql (2.72ms)17412026/10/01 07:34:06 OK 20251218171726_add_pins.sql (2.74ms)17422026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)17432026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (1.83ms)17442026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.92ms)17452026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000017462026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)17472026/10/01 07:34:06 OK 20251218171726_add_pins.sql (2.8ms)17482026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.69ms)17492026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.55ms)17502026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)17512026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.14ms)17522026/10/01 07:34:06 OK 3_commit_push.sql (1.11ms)17532026/10/01 07:34:06 goose: up to current file version: 317542026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.06ms)17552026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.73ms)17562026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.68ms)17572026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000017582026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.43ms)17592026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.5ms)17602026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.48ms)17612026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000017622026/10/01 07:34:06 OK 2_object_stats_trigger.sql (2.32ms)1763=== NAME TestClientWithDependencies1764 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1936245245/001/store/j8qsjq1492021jc5z89p1wlgkh2bhz11-test-script1765=== NAME TestClientMultipleUploads1766 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads553613259/001/store/akxcx997fm6wm45aplr8912dwhz3w4x0-test-file-0.txt17672026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.47ms)17682026/10/01 07:34:06 OK 3_commit_push.sql (2.45ms)17692026/10/01 07:34:06 goose: up to current file version: 317702026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.53ms)17712026/10/01 07:34:06 OK 3_commit_push.sql (1.73ms)17722026/10/01 07:34:06 goose: up to current file version: 317732026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes17742026/10/01 07:34:06 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17752026/10/01 07:34:06 INFO Uploading 40dgacshc726qll6qb4knw9y24snq98j-top (224B)17762026/10/01 07:34:06 INFO Uploading 5fsrp5hiysx43iqbkwa7y5a7vrlmymlv-shared-dep (136B)17772026/10/01 07:34:06 WARN Failed to register uploaded object key=5fsrp5hiysx43iqbkwa7y5a7vrlmymlv.ls error="server returned 404: 404 page not found\n"17782026/10/01 07:34:06 WARN Failed to register uploaded object key=40dgacshc726qll6qb4knw9y24snq98j.ls error="server returned 404: 404 page not found\n"17792026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/0w2sb0xnvfp0ql6pk0wwjcmmh7ixi108xwm90ikqlc3ixhdk2hh1.nar.zst error="server returned 404: 404 page not found\n"17802026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17812026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17822026/10/01 07:34:06 INFO Signed narinfos id=1 count=217832026/10/01 07:34:06 INFO Uploading 2 narinfos17842026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete17852026/10/01 07:34:06 WARN Failed to register uploaded object key=5fsrp5hiysx43iqbkwa7y5a7vrlmymlv.narinfo error="server returned 404: 404 page not found\n"17862026/10/01 07:34:06 WARN Failed to register uploaded object key=40dgacshc726qll6qb4knw9y24snq98j.narinfo error="server returned 404: 404 page not found\n"1787 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads553613259/001/store/r78ji9zlqkj7njcy75019f7hdr5ry4l5-test-file-1.txt17882026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes17892026/10/01 07:34:06 INFO Upload complete. (64ms)17902026/10/01 07:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17912026/10/01 07:34:06 INFO Uploading 5hlql1vd13q43rnnk5qhwzpcpz5i2gqp-unpinned-file.txt (128B)1792=== NAME TestClientSharedPathCommittedMidPush1793 client_integration_test.go:680: Retrieved narinfo from S3:1794 StorePath: /build/TestClientSharedPathCommittedMidPush253140607/001/store/5fsrp5hiysx43iqbkwa7y5a7vrlmymlv-shared-dep1795 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1796 Compression: zstd1797 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821798 NarSize: 1361799 References: 1800 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1801=== NAME TestClientWithDependencies1802 client_integration_test.go:615: Found 1 dependencies (including self)1803=== NAME TestClientSharedPathCommittedMidPush1804 client_integration_test.go:680: Retrieved narinfo from S3:1805 StorePath: /build/TestClientSharedPathCommittedMidPush253140607/001/store/40dgacshc726qll6qb4knw9y24snq98j-top1806 URL: nar/0w2sb0xnvfp0ql6pk0wwjcmmh7ixi108xwm90ikqlc3ixhdk2hh1.nar.zst1807 Compression: zstd1808 NarHash: sha256:0w2sb0xnvfp0ql6pk0wwjcmmh7ixi108xwm90ikqlc3ixhdk2hh11809 NarSize: 2241810 References: /build/TestClientSharedPathCommittedMidPush253140607/001/store/5fsrp5hiysx43iqbkwa7y5a7vrlmymlv-shared-dep1811 CA: text:sha256:0qhislxiq3wcwa71mylcn317fnxr9lm0dissvs1ll79rb7mirnzy18122026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18132026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18142026/10/01 07:34:06 INFO Signed narinfos id=2 count=118152026/10/01 07:34:06 WARN Failed to register uploaded object key=5hlql1vd13q43rnnk5qhwzpcpz5i2gqp.ls error="server returned 404: 404 page not found\n"18162026/10/01 07:34:06 INFO Uploading 1 narinfos1817=== NAME TestClientIntegration1818 client_integration_test.go:286: Created store path: /build/TestClientIntegration3077227306/002/store/1fdwnbk4fkqma9v54akkzxqfpdl2vbia-test-file.txt18192026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes1820--- PASS: TestClientSharedPathCommittedMidPush (1.02s)1821=== CONT TestReadProxyRootRedirectsToIndexHTML18222026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/2/complete18232026/10/01 07:34:06 WARN Failed to register uploaded object key=5hlql1vd13q43rnnk5qhwzpcpz5i2gqp.narinfo error="server returned 404: 404 page not found\n"18242026-10-01 07:34:06.304 UTC [1055] ERROR: relation "goose_db_version" does not exist at character 3618252026-10-01 07:34:06.304 UTC [1055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18262026/10/01 07:34:06 INFO Upload complete. (46ms)18272026/10/01 07:34:06 OK 20241026095416_initial_model.sql (9.7ms)18282026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete18292026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)1830=== NAME TestClientMultipleUploads1831 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads553613259/001/store/00r21bqik2v0smn89vvr8wzr3q2kgg7y-test-file-2.txt18322026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.6ms)1833--- PASS: TestPush_CompleteCommitsEveryRoot (0.82s)1834=== CONT TestReadProxyNarinfoAlreadyDecompressed18352026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)18362026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.83ms)18372026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.73ms)18382026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.29ms)18392026/10/01 07:34:06 goose: successfully migrated database to version: 202609231200001840--- PASS: TestReadRedirectUsesPublicS3URL (0.76s)1841=== CONT TestReadProxyConditionalGet18422026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.6ms)18432026/10/01 07:34:06 INFO Received create pin request method=POST path=/api/pins/myapp18442026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.8ms)18452026/10/01 07:34:06 OK 3_commit_push.sql (1.36ms)18462026/10/01 07:34:06 goose: up to current file version: 318472026/10/01 07:34:06 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3182914843/001/store/vkaxakb3ibzidvh7190vcdwrzq4sazkw-pinned-file.txt narinfo_key=vkaxakb3ibzidvh7190vcdwrzq4sazkw.narinfo18482026/10/01 07:34:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures18492026/10/01 07:34:06 INFO Garbage collection started1850--- PASS: TestCacheStatsHandler (0.79s)1851=== CONT TestReadProxyNarinfo18522026/10/01 07:34:06 INFO Aborted multipart uploads count=018532026/10/01 07:34:06 WARN Force mode enabled - objects will be deleted immediately without grace period18542026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes1855=== NAME TestClientCADerivations1856 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1698791123/001/store/kk6bh3cfhm66l513g731wdayv5bqyyxd-ca-test18572026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes18582026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes18592026/10/01 07:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18602026/10/01 07:34:06 INFO Uploading j8qsjq1492021jc5z89p1wlgkh2bhz11-test-script (136B)18612026/10/01 07:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18622026/10/01 07:34:06 INFO Uploading 1fdwnbk4fkqma9v54akkzxqfpdl2vbia-test-file.txt (152B)18632026/10/01 07:34:06 WARN Failed to register uploaded object key=j8qsjq1492021jc5z89p1wlgkh2bhz11.ls error="server returned 404: 404 page not found\n"18642026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18652026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18662026/10/01 07:34:06 WARN Failed to register uploaded object key=log/8ly77krbmwpc9f6zb5s55anv7w3gnzw5-test-script.drv error="server returned 404: 404 page not found\n"18672026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18682026/10/01 07:34:06 WARN Failed to register uploaded object key=1fdwnbk4fkqma9v54akkzxqfpdl2vbia.ls error="server returned 404: 404 page not found\n"18692026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18702026/10/01 07:34:06 INFO Signed narinfos id=1 count=118712026/10/01 07:34:06 INFO Uploading 1 narinfos18722026/10/01 07:34:06 INFO Signed narinfos id=1 count=118732026/10/01 07:34:06 INFO Uploading 1 narinfos18742026/10/01 07:34:06 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=01875--- PASS: TestService_ReadScope_PublicByDefault (0.80s)1876=== CONT TestReadProxyHead18772026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete18782026/10/01 07:34:06 WARN Failed to register uploaded object key=j8qsjq1492021jc5z89p1wlgkh2bhz11.narinfo error="server returned 404: 404 page not found\n"18792026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete18802026-10-01 07:34:06.393 UTC [1226] ERROR: relation "goose_db_version" does not exist at character 3618812026-10-01 07:34:06.393 UTC [1226] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18822026/10/01 07:34:06 WARN Failed to register uploaded object key=1fdwnbk4fkqma9v54akkzxqfpdl2vbia.narinfo error="server returned 404: 404 page not found\n"18832026/10/01 07:34:06 INFO Vacuumed table table=pending_closures1884--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.82s)1885=== CONT TestIsValidCachePath1886=== RUN TestIsValidCachePath/narinfo1887=== PAUSE TestIsValidCachePath/narinfo1888=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1889=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1890=== RUN TestIsValidCachePath/nar_zst1891=== PAUSE TestIsValidCachePath/nar_zst1892=== RUN TestIsValidCachePath/nar_xz1893=== PAUSE TestIsValidCachePath/nar_xz1894=== RUN TestIsValidCachePath/nar_bz21895=== PAUSE TestIsValidCachePath/nar_bz21896=== RUN TestIsValidCachePath/nar_uncompressed1897=== PAUSE TestIsValidCachePath/nar_uncompressed1898=== RUN TestIsValidCachePath/ls1899=== PAUSE TestIsValidCachePath/ls1900=== RUN TestIsValidCachePath/log1901=== PAUSE TestIsValidCachePath/log1902=== RUN TestIsValidCachePath/realisation1903=== PAUSE TestIsValidCachePath/realisation1904=== RUN TestIsValidCachePath/nix-cache-info1905=== PAUSE TestIsValidCachePath/nix-cache-info1906=== RUN TestIsValidCachePath/index.html1907=== PAUSE TestIsValidCachePath/index.html1908=== RUN TestIsValidCachePath/traversal_parent1909=== PAUSE TestIsValidCachePath/traversal_parent1910=== RUN TestIsValidCachePath/traversal_in_middle1911=== PAUSE TestIsValidCachePath/traversal_in_middle1912=== RUN TestIsValidCachePath/invalid_char_e1913=== PAUSE TestIsValidCachePath/invalid_char_e1914=== RUN TestIsValidCachePath/invalid_char_u1915=== PAUSE TestIsValidCachePath/invalid_char_u1916=== RUN TestIsValidCachePath/random_path1917=== PAUSE TestIsValidCachePath/random_path1918=== RUN TestIsValidCachePath/empty1919=== PAUSE TestIsValidCachePath/empty1920=== RUN TestIsValidCachePath/leading_slash1921=== PAUSE TestIsValidCachePath/leading_slash1922=== RUN TestIsValidCachePath/wrong_extension1923=== PAUSE TestIsValidCachePath/wrong_extension1924=== RUN TestIsValidCachePath/short_hash1925=== PAUSE TestIsValidCachePath/short_hash1926=== CONT TestReadProxyInvalidPath19272026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes19282026/10/01 07:34:06 INFO Vacuumed table table=pending_objects19292026/10/01 07:34:06 INFO Upload complete. (65ms)19302026/10/01 07:34:06 INFO Upload complete. (65ms)19312026/10/01 07:34:06 INFO Vacuumed table table=multipart_uploads1932=== NAME TestClientWithDependencies1933 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1936245245/001/store) requires matching store prefix19342026/10/01 07:34:06 INFO Vacuumed table table=closures19352026/10/01 07:34:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19362026/10/01 07:34:06 INFO Uploading akxcx997fm6wm45aplr8912dwhz3w4x0-test-file-0.txt (160B)19372026/10/01 07:34:06 INFO Uploading 00r21bqik2v0smn89vvr8wzr3q2kgg7y-test-file-2.txt (160B)19382026/10/01 07:34:06 INFO Uploading r78ji9zlqkj7njcy75019f7hdr5ry4l5-test-file-1.txt (160B)19392026/10/01 07:34:06 INFO Vacuumed table table=objects1940=== NAME TestClientCADerivations1941 client_ca_test.go:139: Found 1 dependencies (including self)1942--- PASS: TestClientWithDependencies (1.03s)1943=== CONT TestProxyHeadersOnlyTrustedOnSocket19442026/10/01 07:34:06 WARN Failed to register uploaded object key=00r21bqik2v0smn89vvr8wzr3q2kgg7y.ls error="server returned 404: 404 page not found\n"19452026/10/01 07:34:06 WARN Failed to register uploaded object key=akxcx997fm6wm45aplr8912dwhz3w4x0.ls error="server returned 404: 404 page not found\n"19462026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19472026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19482026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19492026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.48ms)19502026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19512026/10/01 07:34:06 WARN Failed to register uploaded object key=r78ji9zlqkj7njcy75019f7hdr5ry4l5.ls error="server returned 404: 404 page not found\n"19522026/10/01 07:34:06 INFO Signed narinfos id=1 count=319532026/10/01 07:34:06 INFO Uploading 3 narinfos19542026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)19552026/10/01 07:34:06 WARN Failed to register uploaded object key=00r21bqik2v0smn89vvr8wzr3q2kgg7y.narinfo error="server returned 404: 404 page not found\n"19562026/10/01 07:34:06 WARN Failed to register uploaded object key=akxcx997fm6wm45aplr8912dwhz3w4x0.narinfo error="server returned 404: 404 page not found\n"19572026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete19582026/10/01 07:34:06 WARN Failed to register uploaded object key=r78ji9zlqkj7njcy75019f7hdr5ry4l5.narinfo error="server returned 404: 404 page not found\n"19592026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.78ms)19602026-10-01 07:34:06.421 UTC [1277] ERROR: relation "goose_db_version" does not exist at character 3619612026-10-01 07:34:06.421 UTC [1277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19622026-10-01 07:34:06.424 UTC [1278] ERROR: relation "goose_db_version" does not exist at character 3619632026-10-01 07:34:06.424 UTC [1278] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19642026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)19652026/10/01 07:34:06 INFO Upload complete. (68ms)1966=== NAME TestClientMultipleUploads1967 client_integration_test.go:369: Uploaded 3 paths in 100.98569ms1968--- PASS: TestReadProxyRangeRequest (0.84s)1969=== CONT TestNARDeduplicationMetadataUploadBug19702026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.38ms)19712026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.1ms)1972--- PASS: TestClientMultipleUploads (1.04s)1973=== CONT TestObjectStatsTrigger19742026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.71ms)19752026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000019762026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.83ms)19772026-10-01 07:34:06.439 UTC [1298] ERROR: relation "goose_db_version" does not exist at character 3619782026-10-01 07:34:06.439 UTC [1298] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19792026/10/01 07:34:06 INFO All 1 paths already cached19802026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.74ms)1981=== NAME TestClientIntegration1982 client_integration_test.go:312: Retrieved narinfo from S3:1983 StorePath: /build/TestClientIntegration3077227306/002/store/1fdwnbk4fkqma9v54akkzxqfpdl2vbia-test-file.txt1984 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1985 Compression: zstd1986 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11987 NarSize: 1521988 References: 1989 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11990 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1991 client_integration_test.go:313: Decompressed .ls content (64 bytes):1992 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1993 client_integration_test.go:316: Testing garbage collection...19942026/10/01 07:34:06 OK 3_commit_push.sql (6.96ms)19952026/10/01 07:34:06 goose: up to current file version: 319962026/10/01 07:34:06 OK 20241026095416_initial_model.sql (19.31ms)19972026/10/01 07:34:06 OK 20241026095416_initial_model.sql (18.02ms)1998--- PASS: TestReadRedirectKeepsNarinfoProxied (0.82s)1999=== CONT TestIsValidUploadKey2000=== RUN TestIsValidUploadKey/narinfo2001=== PAUSE TestIsValidUploadKey/narinfo2002=== RUN TestIsValidUploadKey/nar_zst2003=== PAUSE TestIsValidUploadKey/nar_zst2004=== RUN TestIsValidUploadKey/nar_xz2005=== PAUSE TestIsValidUploadKey/nar_xz2006=== RUN TestIsValidUploadKey/nar_plain2007=== PAUSE TestIsValidUploadKey/nar_plain2008=== RUN TestIsValidUploadKey/listing2009=== PAUSE TestIsValidUploadKey/listing2010=== RUN TestIsValidUploadKey/build_log2011=== PAUSE TestIsValidUploadKey/build_log2012=== RUN TestIsValidUploadKey/build_log_home-manager_file2013=== PAUSE TestIsValidUploadKey/build_log_home-manager_file2014=== RUN TestIsValidUploadKey/build_log_plus_in_name2015=== PAUSE TestIsValidUploadKey/build_log_plus_in_name2016=== RUN TestIsValidUploadKey/build_log_question_mark2017=== PAUSE TestIsValidUploadKey/build_log_question_mark2018=== RUN TestIsValidUploadKey/build_log_equals2019=== PAUSE TestIsValidUploadKey/build_log_equals2020=== RUN TestIsValidUploadKey/realisation2021=== PAUSE TestIsValidUploadKey/realisation2022=== RUN TestIsValidUploadKey/realisation_plus_in_output2023=== PAUSE TestIsValidUploadKey/realisation_plus_in_output2024=== RUN TestIsValidUploadKey/nix-cache-info2025=== PAUSE TestIsValidUploadKey/nix-cache-info2026=== RUN TestIsValidUploadKey/index.html2027=== PAUSE TestIsValidUploadKey/index.html2028=== RUN TestIsValidUploadKey/narinfo_key,_nar_type2029=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type2030=== RUN TestIsValidUploadKey/nar_key,_narinfo_type2031=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type2032=== RUN TestIsValidUploadKey/listing_key,_narinfo_type2033=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type2034=== RUN TestIsValidUploadKey/traversal2035=== PAUSE TestIsValidUploadKey/traversal2036=== RUN TestIsValidUploadKey/traversal_nar2037=== PAUSE TestIsValidUploadKey/traversal_nar2038=== RUN TestIsValidUploadKey/absolute2039=== PAUSE TestIsValidUploadKey/absolute2040=== RUN TestIsValidUploadKey/empty_key2041=== PAUSE TestIsValidUploadKey/empty_key20422026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)2043=== RUN TestIsValidUploadKey/unknown_type2044=== PAUSE TestIsValidUploadKey/unknown_type2045=== CONT TestMultipartCleanup20462026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)20472026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.24ms)20482026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.55ms)20492026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.76ms)20502026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)20512026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)20522026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)20532026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.28ms)20542026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.44ms)20552026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.15ms)20562026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.15ms)20572026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.94ms)20582026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)20592026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (3.4ms)20602026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000020612026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.84ms)20622026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000020632026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.5ms)20642026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.93ms)20652026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.6ms)20662026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.75ms)20672026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.96ms)20682026/10/01 07:34:06 OK 3_commit_push.sql (1.57ms)20692026/10/01 07:34:06 goose: up to current file version: 320702026-10-01 07:34:06.479 UTC [1322] ERROR: relation "goose_db_version" does not exist at character 3620712026-10-01 07:34:06.479 UTC [1322] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20722026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.62ms)20732026/10/01 07:34:06 OK 3_commit_push.sql (2.39ms)20742026/10/01 07:34:06 goose: up to current file version: 320752026/10/01 07:34:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures20762026-10-01 07:34:06.481 UTC [1357] ERROR: relation "goose_db_version" does not exist at character 3620772026-10-01 07:34:06.481 UTC [1357] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20782026/10/01 07:34:06 INFO Garbage collection started20792026-10-01 07:34:06.482 UTC [1358] ERROR: relation "goose_db_version" does not exist at character 3620802026-10-01 07:34:06.482 UTC [1358] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20812026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (3.22ms)20822026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000020832026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.25ms)2084=== RUN TestService_RequireScope_OIDC/builder_may_write2085=== PAUSE TestService_RequireScope_OIDC/builder_may_write2086=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2087=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2088=== RUN TestService_RequireScope_OIDC/ops_may_admin2089=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2090=== RUN TestService_RequireScope_OIDC/ops_may_not_write2091=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2092=== RUN TestService_RequireScope_OIDC/reader_may_not_write2093=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2094=== RUN TestService_RequireScope_OIDC/static_token_may_admin2095=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2096=== RUN TestService_RequireScope_OIDC/static_token_may_write2097=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2098=== RUN TestService_RequireScope_OIDC/reader_may_read2099=== PAUSE TestService_RequireScope_OIDC/reader_may_read2100=== RUN TestService_RequireScope_OIDC/writer_implies_read2101=== PAUSE TestService_RequireScope_OIDC/writer_implies_read21022026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.6ms)2103=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2104=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2105=== CONT TestCreatePin_ReservedPins21062026/10/01 07:34:06 OK 3_commit_push.sql (1.48ms)21072026/10/01 07:34:06 goose: up to current file version: 321082026/10/01 07:34:06 INFO Aborted multipart uploads count=021092026/10/01 07:34:06 WARN Force mode enabled - objects will be deleted immediately without grace period21102026/10/01 07:34:06 OK 20241026095416_initial_model.sql (13.94ms)21112026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.71ms)21122026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.55ms)2113--- PASS: TestReadRedirectNar (0.45s)2114=== CONT TestUploadHandlersRejectOversizedBody21152026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)21162026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)21172026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)21182026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.65ms)21192026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.6ms)21202026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.47ms)21212026-10-01 07:34:06.508 UTC [1361] ERROR: relation "goose_db_version" does not exist at character 3621222026-10-01 07:34:06.508 UTC [1361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21232026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)21242026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)21252026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)21262026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.07ms)21272026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.9ms)2128=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2129=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2130=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21312026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes2132=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2133=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected21342026/10/01 07:34:06 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=02135=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2136=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2137=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2138=== CONT TestServerTLSConfig2139=== RUN TestServerTLSConfig/no_client_CA2140=== PAUSE TestServerTLSConfig/no_client_CA2141=== RUN TestServerTLSConfig/missing_CA_file2142=== PAUSE TestServerTLSConfig/missing_CA_file2143=== RUN TestServerTLSConfig/not_a_PEM_file2144=== PAUSE TestServerTLSConfig/not_a_PEM_file2145=== CONT TestOrphanedObjectsGCStressTest21462026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.01ms)21472026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.61ms)21482026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.64ms)21492026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.14ms)21502026/10/01 07:34:06 INFO Vacuumed table table=pending_closures21512026/10/01 07:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21522026/10/01 07:34:06 INFO Uploading kk6bh3cfhm66l513g731wdayv5bqyyxd-ca-test (144B)21532026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.21ms)21542026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000021552026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.82ms)21562026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000021572026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.97ms)21582026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000021592026-10-01 07:34:06.522 UTC [1379] ERROR: relation "goose_db_version" does not exist at character 3621602026-10-01 07:34:06.522 UTC [1379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21612026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.28ms)21622026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.49ms)21632026/10/01 07:34:06 INFO Vacuumed table table=pending_objects21642026/10/01 07:34:06 INFO Vacuumed table table=multipart_uploads21652026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.49ms)21662026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.59ms)21672026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.6ms)21682026/10/01 07:34:06 OK 3_commit_push.sql (768.51µs)21692026/10/01 07:34:06 goose: up to current file version: 321702026/10/01 07:34:06 OK 3_commit_push.sql (995.31µs)21712026/10/01 07:34:06 goose: up to current file version: 321722026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21732026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.73ms)21742026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21752026/10/01 07:34:06 INFO Vacuumed table table=closures21762026/10/01 07:34:06 WARN Failed to register uploaded object key=log/1q2bcdp8jnskbjysc6vi89g6rjks5izz-ca-test.drv error="server returned 404: 404 page not found\n"21772026/10/01 07:34:06 WARN Failed to register uploaded object key=kk6bh3cfhm66l513g731wdayv5bqyyxd.ls error="server returned 404: 404 page not found\n"21782026/10/01 07:34:06 INFO Signed narinfos id=1 count=121792026/10/01 07:34:06 INFO Uploading 1 narinfos21802026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.71ms)21812026/10/01 07:34:06 OK 3_commit_push.sql (1.22ms)21822026/10/01 07:34:06 goose: up to current file version: 321832026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)21842026/10/01 07:34:06 INFO Vacuumed table table=objects21852026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete21862026/10/01 07:34:06 WARN Failed to register uploaded object key=kk6bh3cfhm66l513g731wdayv5bqyyxd.narinfo error="server returned 404: 404 page not found\n"21872026/10/01 07:34:06 OK 20251218171726_add_pins.sql (2.67ms)21882026/10/01 07:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21892026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)21902026/10/01 07:34:06 INFO Upload complete. (94ms)21912026/10/01 07:34:06 OK 20241026095416_initial_model.sql (9.36ms)21922026-10-01 07:34:06.538 UTC [1382] ERROR: relation "goose_db_version" does not exist at character 3621932026-10-01 07:34:06.538 UTC [1382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21942026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.92ms)2195--- PASS: TestService_ReadAuthMiddleware (0.47s)2196=== CONT TestUploadHandlersRejectInvalidKeys2197=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2198=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2199=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2200=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2201=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2202=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2203=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22042026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)2205=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2206=== CONT TestService_NativeMTLS2207=== NAME TestClientCADerivations2208 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1698791123/001/store/kk6bh3cfhm66l513g731wdayv5bqyyxd-ca-test2209 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2210 Compression: zstd2211 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2212 NarSize: 1442213 References: 2214 Deriver: /build/TestClientCADerivations1698791123/001/store/1q2bcdp8jnskbjysc6vi89g6rjks5izz-ca-test.drv2215 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2216 client_ca_test.go:185: Checking for realisation files in S3...22172026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.65ms)2218 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2219 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache22202026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.48ms)22212026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000022222026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.83ms)22232026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.43ms)22242026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.37ms)22252026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.69ms)22262026/10/01 07:34:06 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjkwZmFjNjMtY2RjYy00NGY3LTgwOWItNmM0MDE3NGNjNWI1LmU3ZGYyNTFhLWJhYTYtNDM0Yi1iMzUxLTI0MjFhMGMyMWMzOXgxNzkwODQwMDQ2MjAzMjE3MzAx parts=1022272026/10/01 07:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22282026/10/01 07:34:06 OK 3_commit_push.sql (1.1ms)22292026/10/01 07:34:06 goose: up to current file version: 322302026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.66ms)22312026/10/01 07:34:06 INFO Completed upload id=122322026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.93ms)22332026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures22342026/10/01 07:34:06 OK 20241026095416_initial_model.sql (11.02ms)22352026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.02ms)22362026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000022372026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)22382026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures22392026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.93ms)22402026/10/01 07:34:06 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo22412026/10/01 07:34:06 WARN Found objects in DB but missing from S3, will re-upload count=122422026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.82ms)22432026/10/01 07:34:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22442026/10/01 07:34:06 WARN mTLS auth: bound subjects configured but subject DN unavailable22452026/10/01 07:34:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2246--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.46s)2247=== CONT TestOrphanedObjectsGC22482026/10/01 07:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22492026/10/01 07:34:06 OK 20251218171726_add_pins.sql (4.68ms)2250--- PASS: TestService_verifyS3Integrity (1.17s)2251=== CONT TestMetricsInventory22522026/10/01 07:34:06 OK 3_commit_push.sql (1.57ms)22532026/10/01 07:34:06 goose: up to current file version: 322542026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)22552026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.4ms)22562026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.75ms)22572026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.92ms)22582026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000022592026/10/01 07:34:06 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjkwZmFjNjMtY2RjYy00NGY3LTgwOWItNmM0MDE3NGNjNWI1LmU4ZGEwNDY4LWM2YTItNDM0NC1hNWE4LTBhNGVhMDM4YmMxZXgxNzkwODQwMDQ2MjQwODI2NTA1 parts=1022602026/10/01 07:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22612026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.07ms)22622026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.42ms)22632026/10/01 07:34:06 INFO Completed upload id=122642026/10/01 07:34:06 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000022652026/10/01 07:34:06 OK 3_commit_push.sql (1.44ms)22662026/10/01 07:34:06 goose: up to current file version: 322672026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures2268--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)2269=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle22702026/10/01 07:34:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures22712026-10-01 07:34:06.590 UTC [1409] ERROR: relation "goose_db_version" does not exist at character 3622722026-10-01 07:34:06.590 UTC [1409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22732026/10/01 07:34:06 INFO Aborted multipart uploads count=02274--- PASS: TestReadProxyDisabled (0.46s)2275=== CONT TestService_healthCheckHandler22762026/10/01 07:34:06 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=022772026/10/01 07:34:06 INFO Vacuumed table table=pending_closures22782026/10/01 07:34:06 INFO Vacuumed table table=pending_objects22792026/10/01 07:34:06 OK 20241026095416_initial_model.sql (11.55ms)22802026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)22812026/10/01 07:34:06 INFO Vacuumed table table=multipart_uploads22822026-10-01 07:34:06.619 UTC [1414] ERROR: relation "goose_db_version" does not exist at character 3622832026-10-01 07:34:06.619 UTC [1414] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22842026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.48ms)2285--- PASS: TestReadProxy404 (0.48s)2286=== CONT TestProxyWriteTimeout2287=== RUN TestProxyWriteTimeout/narinfo2288=== PAUSE TestProxyWriteTimeout/narinfo2289=== RUN TestProxyWriteTimeout/1_GiB_nar2290=== PAUSE TestProxyWriteTimeout/1_GiB_nar2291=== RUN TestProxyWriteTimeout/10_GiB_nar2292=== PAUSE TestProxyWriteTimeout/10_GiB_nar2293=== RUN TestProxyWriteTimeout/unknown_size2294=== PAUSE TestProxyWriteTimeout/unknown_size2295=== CONT TestGenerateLandingPage22962026/10/01 07:34:06 INFO Vacuumed table table=closures2297--- PASS: TestGenerateLandingPage (0.00s)2298=== CONT TestCacheConfigHandlerMaxNarSize2299--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2300=== CONT TestGCTaskStore_PhaseUpdates2301--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)23022026/10/01 07:34:06 INFO Vacuumed table table=objects2303=== CONT TestService_readinessHandler23042026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)23052026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.7ms)23062026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.54ms)23072026-10-01 07:34:06.632 UTC [1513] ERROR: relation "goose_db_version" does not exist at character 3623082026-10-01 07:34:06.632 UTC [1513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23092026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.01ms)23102026/10/01 07:34:06 goose: successfully migrated database to version: 202609231200002311=== NAME TestClientCADerivations2312 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2313 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2314 error: binary cache 's3://bucket38?endpoint=http://localhost:33547®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1698791123/001/store'2315 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 123162026/10/01 07:34:06 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002317--- PASS: TestService_createPendingClosureHandler (1.17s)2318=== CONT TestCreatePendingClosureRejectsOversizedNAR23192026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.33ms)23202026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures2321--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2322=== CONT TestGCTaskStore_Fail2323--- PASS: TestGCTaskStore_Fail (0.00s)2324=== CONT TestGCTaskStore_CompletedAllowsNewTask2325--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)2326=== CONT TestGracefulShutdownDrainsInflight23272026/10/01 07:34:06 INFO Starting HTTP server address=127.0.0.1:4297723282026/10/01 07:34:06 INFO Shutdown signal received, draining in-flight requests timeout=10s23292026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.3ms)2330--- PASS: TestClientCADerivations (1.14s)2331=== CONT TestResolveDBConnectionString/flag_wins2332=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2333=== CONT TestResolveDBConnectionString/nothing_configured2334=== CONT TestResolveDBConnectionString/missing_file_is_an_error2335=== CONT TestResolveDBConnectionString/file_when_flag_empty2336=== CONT TestClientErrorHandling/InvalidStorePath2337--- PASS: TestResolveDBConnectionString (0.00s)2338 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2339 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2340 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2341 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2342 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)23432026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.21ms)23442026/10/01 07:34:06 OK 3_commit_push.sql (2.13ms)23452026/10/01 07:34:06 goose: up to current file version: 323462026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)23472026-10-01 07:34:06.641 UTC [1515] ERROR: relation "goose_db_version" does not exist at character 3623482026-10-01 07:34:06.641 UTC [1515] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23492026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.92ms)2350--- PASS: TestReadProxyNarStreaming (0.41s)2351=== CONT TestClientErrorHandling/ServerNotAvailable23522026/10/01 07:34:06 OK 20241026095416_initial_model.sql (9.35ms)23532026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)23542026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)23552026/10/01 07:34:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32775/oidc23562026-10-01 07:34:06.658 UTC [1520] ERROR: relation "goose_db_version" does not exist at character 3623572026-10-01 07:34:06.658 UTC [1520] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23582026/10/01 07:34:06 OK 20260905000000_add_claims.sql (10.71ms)23592026/10/01 07:34:06 OK 20251218171726_add_pins.sql (11.45ms)23602026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.9ms)23612026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.66ms)23622026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)2363--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.36s)2364=== CONT TestClientErrorHandling/InvalidAuthToken2365=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure2366=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure2367=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart2368=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart2369=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts2370=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts2371=== CONT TestParseSingleRange/none2372=== CONT TestParseSingleRange/open-ended2373=== CONT TestParseSingleRange/start_far_past_EOF2374=== CONT TestParseSingleRange/start_past_EOF2375=== CONT TestParseSingleRange/single_byte2376=== CONT TestParseSingleRange/suffix_exceeds_size2377=== CONT TestParseSingleRange/suffix2378=== CONT TestParseSingleRange/end_clamped_to_size2379=== CONT TestParseSingleRange/malformed_both_empty2380=== CONT TestParseSingleRange/multi-range_ignored2381=== CONT TestParseSingleRange/closed2382=== CONT TestParseSingleRange/malformed_no_dash2383=== CONT TestParseSingleRange/malformed_end_before_start2384=== CONT TestParseSingleRange/unknown_unit2385--- PASS: TestParseSingleRange (0.00s)2386 --- PASS: TestParseSingleRange/none (0.00s)2387 --- PASS: TestParseSingleRange/open-ended (0.00s)2388 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2389 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2390 --- PASS: TestParseSingleRange/single_byte (0.00s)2391 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2392 --- PASS: TestParseSingleRange/suffix (0.00s)2393 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2394 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2395 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2396 --- PASS: TestParseSingleRange/closed (0.00s)2397 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2398 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2399 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2400=== CONT TestCacheConfigHandler/full_config,_no_issuer2401=== CONT TestCacheConfigHandler/no_signing_keys2402=== CONT TestCacheConfigHandler/no_cache_url_configured24032026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.55ms)2404=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2405--- PASS: TestCacheConfigHandler (0.00s)2406 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2407 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2408 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2409 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2410=== CONT TestPush_RejectsBadRequests/no_roots24112026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.9ms)24122026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes2413=== CONT TestPush_RejectsBadRequests/bad_root24142026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000024152026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes2416=== CONT TestPush_RejectsBadRequests/root_not_in_objects24172026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes2418=== CONT TestPush_RejectsBadRequests/no_objects24192026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes2420=== CONT TestIsValidCachePath/narinfo2421=== CONT TestIsValidCachePath/short_hash2422=== CONT TestIsValidCachePath/wrong_extension2423=== CONT TestIsValidCachePath/leading_slash2424=== CONT TestIsValidCachePath/empty2425--- PASS: TestPush_RejectsBadRequests (0.76s)2426 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2427 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2428 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2429 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2430=== CONT TestIsValidCachePath/random_path2431=== CONT TestIsValidCachePath/invalid_char_u2432=== CONT TestIsValidCachePath/invalid_char_e2433=== CONT TestIsValidCachePath/traversal_in_middle2434=== CONT TestIsValidCachePath/traversal_parent2435=== CONT TestIsValidCachePath/index.html2436=== CONT TestIsValidCachePath/nix-cache-info2437=== CONT TestIsValidCachePath/realisation2438=== CONT TestIsValidCachePath/log2439=== CONT TestIsValidCachePath/ls2440=== CONT TestIsValidCachePath/nar_uncompressed2441=== CONT TestIsValidCachePath/nar_zst2442=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2443=== CONT TestIsValidCachePath/nar_bz22444=== CONT TestIsValidCachePath/nar_xz2445=== CONT TestIsValidUploadKey/narinfo2446=== CONT TestIsValidUploadKey/absolute2447=== CONT TestIsValidUploadKey/traversal_nar2448=== CONT TestIsValidUploadKey/traversal2449--- PASS: TestIsValidCachePath (0.00s)2450 --- PASS: TestIsValidCachePath/narinfo (0.00s)2451 --- PASS: TestIsValidCachePath/short_hash (0.00s)2452 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2453 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2454 --- PASS: TestIsValidCachePath/empty (0.00s)2455 --- PASS: TestIsValidCachePath/random_path (0.00s)2456 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2457 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2458 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2459 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2460 --- PASS: TestIsValidCachePath/index.html (0.00s)2461 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2462 --- PASS: TestIsValidCachePath/realisation (0.00s)2463 --- PASS: TestIsValidCachePath/log (0.00s)2464 --- PASS: TestIsValidCachePath/ls (0.00s)2465 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2466 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2467 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2468 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2469 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2470=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2471=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2472=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2473=== CONT TestIsValidUploadKey/index.html2474=== CONT TestIsValidUploadKey/nix-cache-info2475=== CONT TestIsValidUploadKey/realisation_plus_in_output2476=== CONT TestIsValidUploadKey/realisation2477=== CONT TestIsValidUploadKey/build_log_equals2478=== CONT TestIsValidUploadKey/build_log_question_mark2479=== CONT TestIsValidUploadKey/build_log_plus_in_name2480=== CONT TestIsValidUploadKey/build_log_home-manager_file2481=== CONT TestIsValidUploadKey/empty_key2482=== CONT TestIsValidUploadKey/build_log2483=== CONT TestIsValidUploadKey/listing2484=== CONT TestIsValidUploadKey/nar_plain2485=== CONT TestIsValidUploadKey/nar_xz2486=== CONT TestIsValidUploadKey/nar_zst2487=== CONT TestIsValidUploadKey/unknown_type2488--- PASS: TestIsValidUploadKey (0.00s)2489 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2490 --- PASS: TestIsValidUploadKey/absolute (0.00s)2491 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2492 --- PASS: TestIsValidUploadKey/traversal (0.00s)2493 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2494 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2495 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2496 --- PASS: TestIsValidUploadKey/index.html (0.00s)2497 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2498 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2499 --- PASS: TestIsValidUploadKey/realisation (0.00s)2500 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2501 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2502 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2503 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2504 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2505 --- PASS: TestIsValidUploadKey/build_log (0.00s)2506 --- PASS: TestIsValidUploadKey/listing (0.00s)2507 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2508 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2509 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2510 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2511=== CONT TestService_RequireScope_OIDC/builder_may_write25122026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.94ms)25132026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.36ms)2514=== CONT TestService_RequireScope_OIDC/static_token_may_admin2515=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2516=== CONT TestService_RequireScope_OIDC/writer_implies_read2517=== CONT TestService_RequireScope_OIDC/reader_may_read2518=== CONT TestService_RequireScope_OIDC/static_token_may_write2519=== CONT TestService_RequireScope_OIDC/ops_may_not_write2520=== CONT TestService_RequireScope_OIDC/reader_may_not_write2521=== CONT TestService_RequireScope_OIDC/ops_may_admin25222026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.74ms)2523=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2524=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token25252026/10/01 07:34:06 OK 2_object_stats_trigger.sql (2.02ms)2526--- PASS: TestService_RequireScope_OIDC (0.87s)2527 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2528 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2529 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2530 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2531 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2532 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2533 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2534 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2535 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2536 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)25372026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)25382026/10/01 07:34:06 OK 3_commit_push.sql (1.89ms)25392026/10/01 07:34:06 goose: up to current file version: 325402026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (3.62ms)2541=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected25422026/10/01 07:34:06 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]2543=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2544=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected25452026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.56ms)25462026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.58ms)25472026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000025482026/10/01 07:34:06 WARN Authentication failed token_preview=eyJhbGciOi...ix6SNfk1OQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2549=== CONT TestServerTLSConfig/no_client_CA2550=== CONT TestServerTLSConfig/not_a_PEM_file25512026-10-01 07:34:06.677 UTC [1524] ERROR: relation "goose_db_version" does not exist at character 3625522026-10-01 07:34:06.677 UTC [1524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2553--- PASS: TestService_AuthMiddleware_OIDC (0.54s)2554 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2555 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2556 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2557 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)25582026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.81ms)25592026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.5ms)2560=== CONT TestServerTLSConfig/missing_CA_file2561--- PASS: TestServerTLSConfig (0.00s)2562 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2563 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2564 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2565=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info25662026/10/01 07:34:06 INFO Received uploads request method=POST path=/2567=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key25682026/10/01 07:34:06 INFO Received complete multipart upload request method=POST path=/2569=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal25702026/10/01 07:34:06 INFO Received uploads request method=POST path=/2571=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key25722026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.69ms)25732026/10/01 07:34:06 INFO Received request for more parts method=POST path=/2574--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2575 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2576 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2577 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2578 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2579=== CONT TestProxyWriteTimeout/narinfo2580=== CONT TestProxyWriteTimeout/10_GiB_nar2581=== CONT TestProxyWriteTimeout/1_GiB_nar2582=== CONT TestProxyWriteTimeout/unknown_size2583--- PASS: TestProxyWriteTimeout (0.00s)2584 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2585 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2586 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2587 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2588=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure25892026/10/01 07:34:06 INFO Received uploads request method=POST path=/25902026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)25912026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.77ms)25922026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.44ms)25932026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000025942026/10/01 07:34:06 OK 3_commit_push.sql (1.36ms)25952026/10/01 07:34:06 goose: up to current file version: 325962026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.62ms)25972026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.8ms)25982026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.51ms)25992026/10/01 07:34:06 OK 3_commit_push.sql (1.1ms)26002026/10/01 07:34:06 goose: up to current file version: 326012026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)2602--- PASS: TestReadProxyConditionalGet (0.35s)2603=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts26042026/10/01 07:34:06 INFO Received request for more parts method=POST path=/26052026/10/01 07:34:06 OK 20260905000000_add_claims.sql (4.02ms)26062026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.44ms)26072026-10-01 07:34:06.695 UTC [1542] ERROR: relation "goose_db_version" does not exist at character 3626082026-10-01 07:34:06.695 UTC [1542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26092026/10/01 07:34:06 OK 20241026095416_initial_model.sql (12.46ms)26102026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (2.62ms)26112026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000026122026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)26132026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.12ms)26142026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.31ms)26152026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.04ms)26162026/10/01 07:34:06 OK 3_commit_push.sql (1.28ms)26172026/10/01 07:34:06 goose: up to current file version: 32618--- PASS: TestGracefulShutdownDrainsInflight (0.07s)2619=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart26202026/10/01 07:34:06 INFO Received complete multipart upload request method=POST path=/26212026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)26222026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.88ms)2623--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.38s)26242026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.7ms)26252026/10/01 07:34:06 OK 20241026095416_initial_model.sql (11.29ms)26262026-10-01 07:34:06.715 UTC [1543] ERROR: relation "goose_db_version" does not exist at character 3626272026-10-01 07:34:06.715 UTC [1543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26282026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (8.38ms)26292026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000026302026/10/01 07:34:06 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/present26312026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (8.51ms)26322026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.74ms)26332026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.61ms)26342026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.96ms)26352026/10/01 07:34:06 OK 3_commit_push.sql (1.39ms)26362026/10/01 07:34:06 goose: up to current file version: 32637--- PASS: TestReadProxyNarinfo (0.37s)26382026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)26392026-10-01 07:34:06.733 UTC [1561] ERROR: relation "goose_db_version" does not exist at character 3626402026-10-01 07:34:06.733 UTC [1561] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26412026/10/01 07:34:06 OK 20241026095416_initial_model.sql (10.9ms)26422026/10/01 07:34:06 OK 20260905000000_add_claims.sql (3.78ms)26432026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)26442026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (1.88ms)26452026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.78ms)26462026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000026472026/10/01 07:34:06 OK 20251218171726_add_pins.sql (2.93ms)26482026/10/01 07:34:06 OK 1_commit_pending_closure.sql (1.72ms)2649--- PASS: TestReadProxyInvalidPath (0.34s)26502026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.49ms)26512026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)26522026-10-01 07:34:06.741 UTC [1562] ERROR: relation "goose_db_version" does not exist at character 3626532026-10-01 07:34:06.741 UTC [1562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26542026/10/01 07:34:06 OK 3_commit_push.sql (752.49µs)26552026/10/01 07:34:06 goose: up to current file version: 326562026/10/01 07:34:06 OK 20260905000000_add_claims.sql (2.79ms)26572026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.26ms)26582026/10/01 07:34:06 OK 20241026095416_initial_model.sql (9.85ms)26592026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.94ms)26602026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000026612026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)26622026/10/01 07:34:06 OK 1_commit_pending_closure.sql (2.08ms)26632026/10/01 07:34:06 OK 20251218171726_add_pins.sql (3.73ms)26642026/10/01 07:34:06 OK 2_object_stats_trigger.sql (1.59ms)26652026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)26662026/10/01 07:34:06 OK 20241026095416_initial_model.sql (9.46ms)26672026/10/01 07:34:06 OK 3_commit_push.sql (623.13µs)26682026/10/01 07:34:06 goose: up to current file version: 326692026/10/01 07:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)26702026/10/01 07:34:06 OK 20260905000000_add_claims.sql (2.33ms)26712026/10/01 07:34:06 OK 20251218171726_add_pins.sql (2.44ms)26722026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (2.01ms)26732026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.8ms)26742026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000026752026/10/01 07:34:06 OK 20260628120000_add_object_size_and_stats.sql (2.87ms)26762026/10/01 07:34:06 OK 1_commit_pending_closure.sql (1.56ms)26772026/10/01 07:34:06 OK 2_object_stats_trigger.sql (717.05µs)26782026/10/01 07:34:06 OK 3_commit_push.sql (685.37µs)26792026/10/01 07:34:06 goose: up to current file version: 326802026/10/01 07:34:06 OK 20260905000000_add_claims.sql (2.6ms)2681--- PASS: TestReadProxyHead (0.38s)26822026/10/01 07:34:06 OK 20260920000000_drop_claims.sql (1.84ms)26832026/10/01 07:34:06 OK 20260923120000_add_pushes.sql (1.27ms)26842026/10/01 07:34:06 goose: successfully migrated database to version: 2026092312000026852026/10/01 07:34:06 INFO Starting HTTP server address=127.0.0.1:4275726862026/10/01 07:34:06 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket4222194585/001/proxy.sock26872026/10/01 07:34:06 WARN mTLS auth: subject not in bound subjects subject="CN=someone"26882026/10/01 07:34:06 OK 1_commit_pending_closure.sql (1.55ms)26892026/10/01 07:34:06 INFO Shutdown signal received, draining in-flight requests timeout=10s2690--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.37s)26912026/10/01 07:34:06 OK 2_object_stats_trigger.sql (640.29µs)26922026/10/01 07:34:06 OK 3_commit_push.sql (482.32µs)26932026/10/01 07:34:06 goose: up to current file version: 32694--- PASS: TestObjectStatsTrigger (0.38s)26952026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures26962026/10/01 07:34:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.238012ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2697=== NAME TestNARDeduplicationMetadataUploadBug2698 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3167941150/001/store/f0clcwhd0cjpw91a2bwgw1yvbhw0lwmd-file1.txt26992026/10/01 07:34:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"27002026/10/01 07:34:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2701--- PASS: TestService_NativeMTLS (0.31s)2702--- PASS: TestMetricsInventory (0.34s)27032026/10/01 07:34:06 INFO Received push request method=POST path=/api/pushes27042026/10/01 07:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27052026/10/01 07:34:06 INFO Uploading f0clcwhd0cjpw91a2bwgw1yvbhw0lwmd-file1.txt (160B)27062026/10/01 07:34:06 INFO Received uploads request method=POST path=/api/pending_closures27072026/10/01 07:34:06 WARN Failed to register uploaded object key=f0clcwhd0cjpw91a2bwgw1yvbhw0lwmd.ls error="server returned 404: 404 page not found\n"27082026/10/01 07:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27092026/10/01 07:34:06 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"27102026/10/01 07:34:06 INFO Signed narinfos id=1 count=127112026/10/01 07:34:06 INFO Uploading 1 narinfos27122026/10/01 07:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete27132026/10/01 07:34:06 WARN Failed to register uploaded object key=f0clcwhd0cjpw91a2bwgw1yvbhw0lwmd.narinfo error="server returned 404: 404 page not found\n"27142026/10/01 07:34:06 INFO Upload complete. (54ms)2715=== NAME TestNARDeduplicationMetadataUploadBug2716 metadata_upload_test.go:54: Retrieved narinfo from S3:2717 StorePath: /build/TestNARDeduplicationMetadataUploadBug3167941150/001/store/f0clcwhd0cjpw91a2bwgw1yvbhw0lwmd-file1.txt2718 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2719 Compression: zstd2720 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2721 NarSize: 1602722 References: 2723 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2724--- PASS: TestService_healthCheckHandler (0.32s)2725=== NAME TestNARDeduplicationMetadataUploadBug2726 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2727 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2728 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}27292026/10/01 07:34:06 INFO Received cleanup request method=DELETE path=/api/pending_closures27302026/10/01 07:34:06 INFO Aborted multipart uploads count=12731--- PASS: TestMultipartCleanup (0.49s)27322026/10/01 07:34:06 WARN readiness check failed error="closed pool"2733--- PASS: TestService_readinessHandler (0.32s)2734=== NAME TestNARDeduplicationMetadataUploadBug2735 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3167941150/001/store/fi9fcwmxkqjcjaf0iz9p9hfcrlm3fz92-file2.txt27362026/10/01 07:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete27372026/10/01 07:34:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux27382026/10/01 07:34:06 WARN Refused reserved pin name=worker-x86_64-linux27392026/10/01 07:34:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux27402026/10/01 07:34:06 INFO Received create pin request method=POST path=/api/pins/my-app27412026/10/01 07:34:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2742--- PASS: TestCreatePin_ReservedPins (0.50s)27432026/10/01 07:34:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.954847ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27442026/10/01 07:34:07 INFO Received push request method=POST path=/api/pushes27452026/10/01 07:34:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)27462026/10/01 07:34:07 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign27472026/10/01 07:34:07 INFO Signed narinfos id=2 count=127482026/10/01 07:34:07 WARN Failed to register uploaded object key=fi9fcwmxkqjcjaf0iz9p9hfcrlm3fz92.ls error="server returned 404: 404 page not found\n"27492026/10/01 07:34:07 INFO Uploading 1 narinfos27502026/10/01 07:34:07 INFO Received complete push request method=POST path=/api/pushes/2/complete27512026/10/01 07:34:07 WARN Failed to register uploaded object key=fi9fcwmxkqjcjaf0iz9p9hfcrlm3fz92.narinfo error="server returned 404: 404 page not found\n"27522026/10/01 07:34:07 INFO Upload complete. (49ms)2753=== NAME TestNARDeduplicationMetadataUploadBug2754 metadata_upload_test.go:76: Retrieved narinfo from S3:2755 StorePath: /build/TestNARDeduplicationMetadataUploadBug3167941150/001/store/fi9fcwmxkqjcjaf0iz9p9hfcrlm3fz92-file2.txt2756 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2757 Compression: zstd2758 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2759 NarSize: 1602760 References: 2761 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2762 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2763 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2764 {"version":1,"root":{"type":"regular","size":44}}2765--- PASS: TestNARDeduplicationMetadataUploadBug (0.62s)27662026/10/01 07:34:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27672026/10/01 07:34:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2768=== NAME TestOrphanedObjectsGC2769 orphaned_objects_gc_test.go:290: GC Test Summary:2770 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2771 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2772 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2773 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2774 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2775--- PASS: TestOrphanedObjectsGC (0.59s)27762026/10/01 07:34:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.203258ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2777--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2778 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2779 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2780 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.96s)2781=== NAME TestOrphanedObjectsGCStressTest2782 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2783 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2784 orphaned_objects_gc_test.go:509: Stress test completed successfully:2785 orphaned_objects_gc_test.go:510: - Active objects preserved: 202786 orphaned_objects_gc_test.go:511: - Objects deleted: 2102787 orphaned_objects_gc_test.go:512: - Total GC'd: 2102788--- PASS: TestOrphanedObjectsGCStressTest (1.54s)27892026/10/01 07:34:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.632275851s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27902026/10/01 07:34:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02791=== NAME TestPinProtectsFromGC2792 client_integration_test.go:794: Pin successfully protected closure from garbage collection2793--- PASS: TestPinProtectsFromGC (3.14s)27942026/10/01 07:34:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02795=== NAME TestClientIntegration2796 client_integration_test.go:323: Objects in database after GC:2797 client_integration_test.go:323: Successfully deleted all objects with GC --force2798--- PASS: TestClientIntegration (3.02s)27992026/10/01 07:34:09 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-config28002026/10/01 07:34:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.816722ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28012026/10/01 07:34:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.382181ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28022026/10/01 07:34:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=745.884146ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28032026/10/01 07:34:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.490453827s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28042026/10/01 07:34:11 WARN Rate limiter enabled after throttle name=s3-test rate=528052026/10/01 07:34:11 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2806=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2807 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102808 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002809--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.23s)28102026/10/01 07:34:12 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"28112026/10/01 07:34:12 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-config28122026/10/01 07:34:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.118979ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28132026/10/01 07:34:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.107173ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28142026/10/01 07:34:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=808.186447ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28152026/10/01 07:34:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.728125715s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28162026/10/01 07:34:16 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_closures28172026/10/01 07:34:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.31834ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28182026/10/01 07:34:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.85679ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28192026/10/01 07:34:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=871.468832ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28202026/10/01 07:34:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.444839064s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2821--- PASS: TestClientErrorHandling (0.00s)2822 --- PASS: TestClientErrorHandling/InvalidStorePath (0.36s)2823 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.43s)2824 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.43s)2825PASS28262026-10-01 07:34:19.297 UTC [129] LOG: received smart shutdown request28272026-10-01 07:34:19.301 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 128282026-10-01 07:34:19.312 UTC [134] LOG: shutting down28292026-10-01 07:34:19.312 UTC [134] LOG: checkpoint starting: shutdown immediate28302026-10-01 07:34:20.160 UTC [134] LOG: checkpoint complete: wrote 11035 buffers (67.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 21 recycled; write=0.186 s, sync=0.637 s, total=0.848 s; sync files=24927, longest=0.002 s, average=0.001 s; distance=339142 kB, estimate=339142 kB; lsn=0/16297680, redo lsn=0/1629768028312026-10-01 07:34:20.238 UTC [129] LOG: database system is shut down2832Running OIDC tests...2833=== RUN TestAudienceForIssuer2834=== PAUSE TestAudienceForIssuer2835=== RUN TestGlobMatch2836=== PAUSE TestGlobMatch2837=== RUN TestValidateToken_ValidToken2838=== PAUSE TestValidateToken_ValidToken2839=== RUN TestValidateToken_WrongAudience2840=== PAUSE TestValidateToken_WrongAudience2841=== RUN TestValidateToken_Expired2842=== PAUSE TestValidateToken_Expired2843=== RUN TestValidateToken_BoundClaimsMismatch2844=== PAUSE TestValidateToken_BoundClaimsMismatch2845=== RUN TestValidateToken_BoundSubjectMismatch2846=== PAUSE TestValidateToken_BoundSubjectMismatch2847=== RUN TestValidateToken_MultipleProviders2848=== PAUSE TestValidateToken_MultipleProviders2849=== RUN TestValidateToken_NoMatchingProvider2850=== PAUSE TestValidateToken_NoMatchingProvider2851=== RUN TestValidateToken_KubernetesServiceAccount2852=== PAUSE TestValidateToken_KubernetesServiceAccount2853=== RUN TestNewValidator_KubernetesRequiresCA2854=== PAUSE TestNewValidator_KubernetesRequiresCA2855=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2856=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2857=== RUN TestPins_ReservedForMatchingRule2858=== PAUSE TestPins_ReservedForMatchingRule2859=== RUN TestPins_TopLevelShorthand2860=== PAUSE TestPins_TopLevelShorthand2861=== RUN TestPins_ConfigValidation2862=== PAUSE TestPins_ConfigValidation2863=== RUN TestScopes_LegacyProviderDefaultsToWrite2864=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2865=== RUN TestScopes_Rules2866=== PAUSE TestScopes_Rules2867=== RUN TestScopes_ConfigValidation2868=== PAUSE TestScopes_ConfigValidation2869=== CONT TestAudienceForIssuer2870=== CONT TestPins_ConfigValidation2871--- PASS: TestAudienceForIssuer (0.00s)2872=== CONT TestValidateToken_NoMatchingProvider2873=== CONT TestValidateToken_KubernetesServiceAccount2874=== CONT TestScopes_Rules2875=== CONT TestScopes_LegacyProviderDefaultsToWrite2876=== CONT TestValidateToken_Expired2877=== CONT TestValidateToken_ValidToken2878=== CONT TestScopes_ConfigValidation2879=== CONT TestPins_ReservedForMatchingRule2880=== CONT TestGlobMatch2881=== RUN TestGlobMatch/foo_foo2882=== PAUSE TestGlobMatch/foo_foo2883=== RUN TestGlobMatch/foo_bar2884=== PAUSE TestGlobMatch/foo_bar2885=== RUN TestGlobMatch/*_2886=== PAUSE TestGlobMatch/*_2887=== RUN TestGlobMatch/*_anything2888=== PAUSE TestGlobMatch/*_anything2889=== RUN TestGlobMatch/foo*_foo2890=== PAUSE TestGlobMatch/foo*_foo2891=== RUN TestGlobMatch/foo*_foobar2892=== PAUSE TestGlobMatch/foo*_foobar2893=== RUN TestGlobMatch/foo*_bar2894=== PAUSE TestGlobMatch/foo*_bar2895=== RUN TestGlobMatch/*bar_bar2896=== PAUSE TestGlobMatch/*bar_bar2897=== RUN TestGlobMatch/*bar_foobar2898=== PAUSE TestGlobMatch/*bar_foobar2899=== RUN TestGlobMatch/*bar_foo2900=== PAUSE TestGlobMatch/*bar_foo2901=== RUN TestGlobMatch/foo*bar_foobar2902=== PAUSE TestGlobMatch/foo*bar_foobar2903=== RUN TestGlobMatch/foo*bar_foo123bar2904=== PAUSE TestGlobMatch/foo*bar_foo123bar2905=== CONT TestValidateToken_BoundSubjectMismatch2906=== RUN TestGlobMatch/foo*bar_foobarbaz2907=== PAUSE TestGlobMatch/foo*bar_foobarbaz2908=== RUN TestGlobMatch/*/*_foo/bar2909=== PAUSE TestGlobMatch/*/*_foo/bar2910=== CONT TestValidateToken_BoundClaimsMismatch2911=== CONT TestPins_TopLevelShorthand2912=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2913=== CONT TestValidateToken_MultipleProviders2914=== CONT TestNewValidator_KubernetesRequiresCA2915=== CONT TestValidateToken_WrongAudience2916--- PASS: TestScopes_ConfigValidation (0.00s)2917--- PASS: TestPins_ConfigValidation (0.00s)2918=== RUN TestGlobMatch/*/*_foo2919=== PAUSE TestGlobMatch/*/*_foo2920=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2921=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2922=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02923=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02924=== RUN TestGlobMatch/refs/*/main_refs/heads/main2925=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2926=== RUN TestGlobMatch/fo?_foo2927=== PAUSE TestGlobMatch/fo?_foo2928=== RUN TestGlobMatch/fo?_fo2929=== PAUSE TestGlobMatch/fo?_fo2930=== RUN TestGlobMatch/fo?_fooo2931=== PAUSE TestGlobMatch/fo?_fooo2932=== RUN TestGlobMatch/?oo_foo2933=== PAUSE TestGlobMatch/?oo_foo2934=== RUN TestGlobMatch/?oo_boo2935=== PAUSE TestGlobMatch/?oo_boo2936=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2937=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2938=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2939=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2940=== CONT TestGlobMatch/foo_foo2941=== CONT TestGlobMatch/foo*bar_foobar2942=== CONT TestGlobMatch/*bar_foo2943=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2944=== CONT TestGlobMatch/*_2945=== CONT TestGlobMatch/foo_bar2946=== CONT TestGlobMatch/?oo_boo2947=== CONT TestGlobMatch/?oo_foo2948=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2949=== CONT TestGlobMatch/refs/*/main_refs/heads/main2950=== CONT TestGlobMatch/fo?_foo2951=== CONT TestGlobMatch/*/*_foo2952=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02953=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2954=== CONT TestGlobMatch/*/*_foo/bar2955=== CONT TestGlobMatch/foo*bar_foobarbaz2956=== CONT TestGlobMatch/fo?_fo2957=== CONT TestGlobMatch/*bar_bar2958=== CONT TestGlobMatch/foo*_bar2959=== CONT TestGlobMatch/foo*_foobar2960=== CONT TestGlobMatch/foo*_foo2961=== CONT TestGlobMatch/*_anything2962=== CONT TestGlobMatch/foo*bar_foo123bar2963=== CONT TestGlobMatch/fo?_fooo2964=== CONT TestGlobMatch/*bar_foobar2965--- PASS: TestGlobMatch (0.00s)2966 --- PASS: TestGlobMatch/foo_foo (0.00s)2967 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2968 --- PASS: TestGlobMatch/*bar_foo (0.00s)2969 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2970 --- PASS: TestGlobMatch/*_ (0.00s)2971 --- PASS: TestGlobMatch/foo_bar (0.00s)2972 --- PASS: TestGlobMatch/?oo_boo (0.00s)2973 --- PASS: TestGlobMatch/?oo_foo (0.00s)2974 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2975 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2976 --- PASS: TestGlobMatch/fo?_foo (0.00s)2977 --- PASS: TestGlobMatch/*/*_foo (0.00s)2978 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2979 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2980 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2981 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2982 --- PASS: TestGlobMatch/fo?_fo (0.00s)2983 --- PASS: TestGlobMatch/*bar_bar (0.00s)2984 --- PASS: TestGlobMatch/foo*_bar (0.00s)2985 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2986 --- PASS: TestGlobMatch/foo*_foo (0.00s)2987 --- PASS: TestGlobMatch/*_anything (0.00s)2988 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2989 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2990 --- PASS: TestGlobMatch/*bar_foobar (0.00s)29912026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34607/oidc29922026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37353/oidc2993--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)2994--- PASS: TestScopes_Rules (0.05s)29952026/10/01 07:34:21 http: TLS handshake error from 127.0.0.1:56046: remote error: tls: bad certificate2996--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)29972026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33213/oidc2998--- PASS: TestPins_TopLevelShorthand (0.12s)29992026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37605/oidc3000--- PASS: TestValidateToken_WrongAudience (0.13s)30012026/10/01 07:34:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46271/oidc30022026/10/01 07:34:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233003--- PASS: TestValidateToken_NoMatchingProvider (0.14s)3004--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.14s)30052026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44593/oidc3006--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.15s)30072026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41301/oidc30082026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44795/oidc30092026/10/01 07:34:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:414733010--- PASS: TestValidateToken_Expired (0.17s)3011--- PASS: TestPins_ReservedForMatchingRule (0.18s)3012--- PASS: TestValidateToken_KubernetesServiceAccount (0.18s)30132026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44005/oidc30142026/10/01 07:34:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40051/oidc3015--- PASS: TestValidateToken_ValidToken (0.32s)3016--- PASS: TestValidateToken_BoundSubjectMismatch (0.32s)30172026/10/01 07:34:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37297/oidc30182026/10/01 07:34:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35925/oidc3019--- PASS: TestValidateToken_MultipleProviders (0.34s)3020PASS3021Running hook tests...3022=== RUN TestSendPathsEmpty3023=== PAUSE TestSendPathsEmpty3024=== RUN TestQueueEnqueueAndFetch3025=== PAUSE TestQueueEnqueueAndFetch3026=== RUN TestQueueDeduplication3027=== PAUSE TestQueueDeduplication3028=== RUN TestQueueRemove3029=== PAUSE TestQueueRemove3030=== RUN TestQueueFetchBatchLimit3031=== PAUSE TestQueueFetchBatchLimit3032=== RUN TestQueueRetryMovesToBack3033=== PAUSE TestQueueRetryMovesToBack3034=== RUN TestQueueFetchRemoveLifecycle3035=== PAUSE TestQueueFetchRemoveLifecycle3036=== RUN TestQueueConcurrentWriters3037=== PAUSE TestQueueConcurrentWriters3038=== RUN TestQueueRemoveLargeClosure3039=== PAUSE TestQueueRemoveLargeClosure3040=== RUN TestServerClientIntegration3041=== PAUSE TestServerClientIntegration3042=== RUN TestServerQueueError3043=== PAUSE TestServerQueueError3044=== RUN TestGetListenerSocketActivation3045 server_test.go:210: === RUN TestGetListenerSocketActivation3046 --- PASS: TestGetListenerSocketActivation (0.00s)3047 PASS3048 3049--- PASS: TestGetListenerSocketActivation (0.01s)3050=== RUN TestDrainIsolatesPoisonPath3051=== PAUSE TestDrainIsolatesPoisonPath3052=== RUN TestRunNotBlockedByPoisonHead3053=== PAUSE TestRunNotBlockedByPoisonHead3054=== RUN TestDrainGivesUpWhenServerDown3055=== PAUSE TestDrainGivesUpWhenServerDown3056=== RUN TestFailedPathPrunedByLaterClosure3057=== PAUSE TestFailedPathPrunedByLaterClosure3058=== RUN TestWorkerUploadsAndRemoves3059=== PAUSE TestWorkerUploadsAndRemoves3060=== RUN TestWorkerSkipsGCdPaths3061=== PAUSE TestWorkerSkipsGCdPaths3062=== RUN TestWorkerPrunesClosureDeps3063=== PAUSE TestWorkerPrunesClosureDeps3064=== RUN TestDrainTimeout3065=== PAUSE TestDrainTimeout3066=== CONT TestSendPathsEmpty3067=== CONT TestDrainIsolatesPoisonPath3068=== CONT TestQueueConcurrentWriters3069--- PASS: TestSendPathsEmpty (0.00s)3070=== CONT TestQueueRetryMovesToBack3071=== CONT TestQueueFetchRemoveLifecycle3072=== CONT TestServerQueueError3073=== CONT TestQueueFetchBatchLimit3074=== CONT TestServerClientIntegration3075=== CONT TestQueueRemove3076=== CONT TestQueueDeduplication3077=== CONT TestQueueRemoveLargeClosure3078=== CONT TestQueueEnqueueAndFetch3079=== CONT TestWorkerUploadsAndRemoves3080=== CONT TestDrainGivesUpWhenServerDown30812026/10/01 07:34:21 ERROR Failed to queue paths error="permission denied" count=13082=== CONT TestFailedPathPrunedByLaterClosure3083=== CONT TestDrainTimeout3084=== CONT TestWorkerPrunesClosureDeps3085=== CONT TestWorkerSkipsGCdPaths3086=== CONT TestRunNotBlockedByPoisonHead3087--- PASS: TestServerClientIntegration (0.00s)3088--- PASS: TestServerQueueError (0.00s)30892026/10/01 07:34:21 INFO Upload queue status pending=230902026/10/01 07:34:21 INFO Uploading batch count=130912026/10/01 07:34:21 INFO Uploading batch count=230922026/10/01 07:34:21 INFO Upload queue status pending=230932026/10/01 07:34:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2459778902/002/nonexistent30942026/10/01 07:34:21 INFO Upload queue status pending=230952026/10/01 07:34:21 INFO Uploading batch count=130962026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=130972026/10/01 07:34:21 INFO Uploading batch count=230982026/10/01 07:34:21 INFO Uploading batch count=230992026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=23100--- PASS: TestQueueEnqueueAndFetch (0.01s)31012026/10/01 07:34:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814244661/002/a31022026/10/01 07:34:21 INFO Uploading batch count=431032026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=431042026/10/01 07:34:21 INFO Uploading batch count=13105--- PASS: TestQueueRemove (0.01s)31062026/10/01 07:34:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2621660088/002/bbb31072026/10/01 07:34:21 INFO Upload queue status pending=331082026/10/01 07:34:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814244661/002/b31092026/10/01 07:34:21 INFO Uploading batch count=131102026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=13111--- PASS: TestQueueFetchBatchLimit (0.01s)3112--- PASS: TestQueueDeduplication (0.01s)31132026/10/01 07:34:21 INFO Uploading batch count=13114--- PASS: TestQueueRetryMovesToBack (0.02s)3115--- PASS: TestQueueFetchRemoveLifecycle (0.02s)31162026/10/01 07:34:21 INFO Uploading batch count=231172026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=231182026/10/01 07:34:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814244661/002/c31192026/10/01 07:34:21 INFO Uploading batch count=131202026/10/01 07:34:21 INFO Uploading batch count=131212026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=131222026/10/01 07:34:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814244661/002/d31232026/10/01 07:34:21 INFO Uploading batch count=131242026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=131252026/10/01 07:34:21 INFO Uploading batch count=231262026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=231272026/10/01 07:34:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814244661/002/e31282026/10/01 07:34:21 INFO Uploading batch count=131292026/10/01 07:34:21 ERROR Upload failed error="upload failed" count=131302026/10/01 07:34:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3814244661/002/f31312026/10/01 07:34:21 ERROR Drain finished with paths left in queue remaining=13132--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)31332026/10/01 07:34:21 ERROR Drain finished with paths left in queue remaining=103134--- PASS: TestDrainIsolatesPoisonPath (0.02s)3135--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3136--- PASS: TestWorkerSkipsGCdPaths (0.03s)3137--- PASS: TestWorkerUploadsAndRemoves (0.03s)3138--- PASS: TestWorkerPrunesClosureDeps (0.03s)3139--- PASS: TestQueueRemoveLargeClosure (0.15s)3140--- PASS: TestQueueConcurrentWriters (0.20s)31412026/10/01 07:34:22 ERROR Upload failed error="context deadline exceeded" count=231422026/10/01 07:34:22 ERROR Drain finished with paths left in queue remaining=43143--- PASS: TestDrainTimeout (0.21s)31442026/10/01 07:34:22 INFO Uploading batch count=131452026/10/01 07:34:22 INFO Uploading batch count=131462026/10/01 07:34:22 INFO Uploading batch count=131472026/10/01 07:34:22 ERROR Upload failed error="upload failed" count=131482026/10/01 07:34:22 INFO Uploading batch count=131492026/10/01 07:34:22 ERROR Upload failed error="upload failed" count=131502026/10/01 07:34:22 INFO Uploading batch count=131512026/10/01 07:34:22 ERROR Upload failed error="upload failed" count=131522026/10/01 07:34:22 INFO Uploading batch count=131532026/10/01 07:34:22 ERROR Upload failed error="upload failed" count=131542026/10/01 07:34:22 ERROR Drain finished with paths left in queue remaining=13155--- PASS: TestRunNotBlockedByPoisonHead (1.02s)3156PASS