niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #281
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)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 TestEncodeNixBase32WithRealHash97=== CONT TestScriptTokenNoExpiryRerunsEveryCall98=== CONT TestShellSplit99=== CONT TestPathInfoCACompatibility100=== CONT TestFileTokenEmpty101=== CONT TestSetClientTLSDoesNotMutateDefaultTransport102=== CONT TestSetClientTLSErrors103=== CONT TestSetClientTLS104=== CONT TestStreamPushIsolatesFailures105=== CONT TestScriptTokenEmptyCommand106=== CONT TestFileTokenReadsAndCaches107=== CONT TestStreamPushBatchesUnderLoad108=== CONT TestScriptTokenScriptFails1092026/10/01 07:31:53 ERROR Upload failed error="bad path" count=3110=== CONT TestStreamPushReportsEveryPath111=== CONT TestScriptTokenBadJSON112=== CONT TestScriptTokenEmptyToken113=== CONT TestShellSplitErrors114=== CONT TestScriptTokenCachesUntilRefresh115=== CONT TestDoWithRetry_BodyReplayedViaGetBody116=== CONT TestResolveStorePath117=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess118=== CONT TestRateLimiterFeedback119=== CONT TestPathInfoHashCompatibility120=== CONT TestParsePathInfoJSONMultiplePaths121=== CONT TestParsePathInfoJSON122--- PASS: TestEncodeNixBase32WithRealHash (0.00s)123--- PASS: TestShellSplit (0.00s)124=== CONT TestFileTokenMissing125=== RUN TestPathInfoCACompatibility/null_ca_field126--- PASS: TestScriptTokenEmptyCommand (0.00s)127--- PASS: TestFileTokenEmpty (0.00s)128=== CONT TestStaticToken129--- PASS: TestStaticToken (0.00s)130=== CONT TestUploadMultipart_SupersededByPeer131=== PAUSE TestPathInfoCACompatibility/null_ca_field132=== RUN TestPathInfoCACompatibility/old_string_format_-_text133=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text134=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive135=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive136=== RUN TestPathInfoCACompatibility/new_structured_format_-_text137=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text138=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method139=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method140=== RUN TestUploadMultipart_SupersededByPeer/exists141--- PASS: TestStreamPushIsolatesFailures (0.00s)142=== CONT TestDumpPathWriterError143=== PAUSE TestUploadMultipart_SupersededByPeer/exists144--- PASS: TestFileTokenReadsAndCaches (0.00s)145=== RUN TestUploadMultipart_SupersededByPeer/missing146=== PAUSE TestUploadMultipart_SupersededByPeer/missing147=== CONT TestEncodeNixBase32148=== CONT TestDumpPathSingleFile149=== CONT TestStreamPushReportsSignatures150=== RUN TestEncodeNixBase32/test_string_hash151=== RUN TestRateLimiterFeedback/429_enables_limiter152=== CONT TestClientSignaturesByStorePath153=== CONT TestDumpPathMatchesNix154=== CONT TestGetStorePathHash155--- PASS: TestShellSplitErrors (0.00s)1562026/10/01 07:31:53 WARN Rate limiter enabled after throttle name=server-test rate=5157--- PASS: TestStreamPushReportsEveryPath (0.00s)158--- PASS: TestFileTokenMissing (0.00s)159--- PASS: TestClientSignaturesByStorePath (0.00s)160=== PAUSE TestEncodeNixBase32/test_string_hash161=== PAUSE TestRateLimiterFeedback/429_enables_limiter162=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths164=== RUN TestParsePathInfoJSON/Nix_format165=== RUN TestGetStorePathHash/valid_store_path166=== CONT TestConvertHashToNix32167=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== PAUSE TestParsePathInfoJSON/Nix_format169=== RUN TestConvertHashToNix32/SRI_format_to_Nix32170=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths171=== CONT TestPartSizeForNAR1722026/10/01 07:31:53 ERROR Upload failed error=boom count=1173=== RUN TestPartSizeForNAR/zero_stays_at_minimum174=== RUN TestEncodeNixBase32/empty_input175=== PAUSE TestEncodeNixBase32/empty_input176=== CONT TestUploadMultipart_PartsInParallel177=== CONT TestStreamPushRequestLine178=== RUN TestSetClientTLSErrors/missing_cert_file179--- PASS: TestScriptTokenScriptFails (0.00s)180--- PASS: TestResolveStorePath (0.00s)181=== PAUSE TestSetClientTLSErrors/missing_cert_file182=== CONT TestStreamPushGivesUpOnDeadServer183=== CONT TestRegisterUploadedObjectReusesConnections184--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)185--- PASS: TestStreamPushReportsSignatures (0.01s)186--- PASS: TestScriptTokenEmptyToken (0.01s)1872026/10/01 07:31:53 WARN Rate limiter enabled after throttle name=server-test rate=51882026/10/01 07:31:53 ERROR Upload failed error="connection refused" count=201892026/10/01 07:31:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:345951902026/10/01 07:31:53 ERROR Server seems unavailable, giving up on batch untried=171912026/10/01 07:31:53 ERROR Upload failed error=boom count=1192=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1932026/10/01 07:31:53 WARN Rate limiter backed off name=server-test rate=5194=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon195=== RUN TestRateLimiterFeedback/503_enables_limiter196=== CONT TestFilterOversizedClosures197=== PAUSE TestGetStorePathHash/valid_store_path198=== RUN TestParsePathInfoJSON/Lix_format199=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32200=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths201=== CONT TestCaseHackSuffix202=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum203--- PASS: TestDoServerRequestAttachesToken (0.01s)204=== CONT TestPathInfoCACompatibility/null_ca_field2052026/10/01 07:31:53 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34595206=== RUN TestSetClientTLSErrors/missing_key_file207=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method208=== PAUSE TestSetClientTLSErrors/missing_key_file209=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths210=== RUN TestGetStorePathHash/basename_without_hyphen_should_error211=== PAUSE TestParsePathInfoJSON/Lix_format212=== RUN TestFilterOversizedClosures/no_limit_keeps_everything213=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything214--- PASS: TestScriptTokenBadJSON (0.01s)215=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI216=== RUN TestSetClientTLSErrors/missing_ca_file217=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error218=== RUN TestSetClientTLS/rejects_connection_without_client_cert219=== CONT TestPathInfoCACompatibility/new_structured_format_-_text220=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive221=== CONT TestPathInfoCACompatibility/old_string_format_-_text222=== RUN TestPartSizeForNAR/small_stays_at_minimum223=== PAUSE TestPartSizeForNAR/small_stays_at_minimum224=== CONT TestUploadMultipart_SupersededByPeer/missing225=== CONT TestEncodeNixBase32/test_string_hash226=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths227=== CONT TestEncodeNixBase32/empty_input228=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths229=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum230=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum231=== CONT TestUploadMultipart_SupersededByPeer/exists232=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped234--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)235=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI236=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error237=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error238=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error239=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert240=== PAUSE TestSetClientTLSErrors/missing_ca_file241=== RUN TestConvertHashToNix32/already_Nix32_format242=== PAUSE TestConvertHashToNix32/already_Nix32_format243=== RUN TestParsePathInfoJSON/empty_input244=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts245=== PAUSE TestParsePathInfoJSON/empty_input246=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts247--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)248=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512250=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)251=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon252=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512253=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA254=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI255=== PAUSE TestRateLimiterFeedback/503_enables_limiter256=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter257=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter258=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter259=== RUN TestConvertHashToNix32/invalid_format260=== PAUSE TestConvertHashToNix32/invalid_format261=== CONT TestConvertHashToNix32/SRI_format_to_Nix32262=== CONT TestConvertHashToNix32/invalid_format263=== RUN TestFilterOversizedClosures/all_closures_skipped264=== PAUSE TestFilterOversizedClosures/all_closures_skipped265=== CONT TestFilterOversizedClosures/no_limit_keeps_everything266=== RUN TestParsePathInfoJSON/whitespace_only267=== PAUSE TestParsePathInfoJSON/whitespace_only268=== RUN TestPartSizeForNAR/1_TiB269--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)270=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error271--- PASS: TestPathInfoCACompatibility (0.00s)272 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)273 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.06s)274 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)275 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)276 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)277=== CONT TestGetStorePathHash/valid_store_path278=== RUN TestSetClientTLSErrors/invalid_ca_file279=== PAUSE TestSetClientTLSErrors/invalid_ca_file280=== CONT TestSetClientTLSErrors/missing_cert_file281=== CONT TestSetClientTLSErrors/missing_ca_file282=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter283=== CONT TestRateLimiterFeedback/429_enables_limiter284=== CONT TestSetClientTLSErrors/missing_key_file285=== CONT TestSetClientTLSErrors/invalid_ca_file286=== CONT TestRateLimiterFeedback/503_enables_limiter2872026/10/01 07:31:53 WARN Rate limiter enabled after throttle name=server-test rate=52882026/10/01 07:31:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:348552892026/10/01 07:31:53 WARN Rate limiter enabled after throttle name=server-test rate=5290=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2912026/10/01 07:31:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:417612922026/10/01 07:31:53 WARN Rate limiter backed off name=server-test rate=5293=== CONT TestConvertHashToNix32/already_Nix32_format294=== CONT TestFilterOversizedClosures/all_closures_skipped2952026/10/01 07:31:53 WARN Rate limiter backed off name=server-test rate=5296=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2972026/10/01 07:31:53 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=50298=== RUN TestParsePathInfoJSON/invalid_JSON2992026/10/01 07:31:53 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000300=== PAUSE TestParsePathInfoJSON/invalid_JSON301=== PAUSE TestPartSizeForNAR/1_TiB302=== CONT TestParsePathInfoJSON/whitespace_only303=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error304=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error305=== CONT TestGetStorePathHash/basename_without_hyphen_should_error306--- PASS: TestEncodeNixBase32 (0.01s)307 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)308 --- PASS: TestEncodeNixBase32/empty_input (0.00s)309--- PASS: TestPathInfoHashCompatibility (0.06s)310 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)311 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)313 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)314=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter315=== CONT TestParsePathInfoJSON/Nix_format316--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.07s)317--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)318 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)319 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)320--- PASS: TestDumpPathSingleFile (0.07s)321--- PASS: TestConvertHashToNix32 (0.06s)322 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)323 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)324 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)325=== CONT TestParsePathInfoJSON/empty_input326=== CONT TestParsePathInfoJSON/Lix_format327=== CONT TestParsePathInfoJSON/invalid_JSON328=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA329=== RUN TestSetClientTLS/preserves_debug_logging_transport330=== RUN TestPartSizeForNAR/5_TiB_S3_max_object331--- PASS: TestFilterOversizedClosures (0.06s)332 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)333 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)334 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)335--- PASS: TestGetStorePathHash (0.06s)336 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)337 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)338 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)339 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)340=== PAUSE TestSetClientTLS/preserves_debug_logging_transport341=== CONT TestSetClientTLS/rejects_connection_without_client_cert342=== CONT TestSetClientTLS/preserves_debug_logging_transport343--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)344 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)346=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object347=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA348--- PASS: TestRateLimiterFeedback (0.07s)349 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)350 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)351 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)352 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)353--- PASS: TestSetClientTLSErrors (0.07s)354 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)355 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)356 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)357 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)358=== RUN TestPartSizeForNAR/capped_at_5_GiB359=== PAUSE TestPartSizeForNAR/capped_at_5_GiB360=== CONT TestPartSizeForNAR/zero_stays_at_minimum361=== CONT TestPartSizeForNAR/5_TiB_S3_max_object362--- PASS: TestParsePathInfoJSON (0.06s)363 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)364 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)365 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)366 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)367 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)368=== CONT TestPartSizeForNAR/1_TiB369=== CONT TestPartSizeForNAR/capped_at_5_GiB370=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum371=== CONT TestPartSizeForNAR/small_stays_at_minimum372=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts373--- PASS: TestPartSizeForNAR (0.06s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)376 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)377 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)378 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)379 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)3812026/10/01 07:31:53 http: TLS handshake error from 127.0.0.1:45934: remote error: tls: bad certificate382--- PASS: TestStreamPushRequestLine (0.08s)383--- PASS: TestSetClientTLS (0.07s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestCaseHackSuffix (0.09s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.09s)389--- PASS: TestDumpPathWriterError (0.11s)390--- PASS: TestStreamPushBatchesUnderLoad (0.12s)391--- PASS: TestDumpPathMatchesNix (0.15s)392--- PASS: TestUploadMultipart_PartsInParallel (0.68s)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/postgres4151918893/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/postgres4151918893/data -l logfile start422423/build/postgres4151918893:5432 - no response4242026-10-01 07:31:55.235 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 07:31:55.235 UTC [129] LOG: listening on Unix socket "/build/postgres4151918893/.s.PGSQL.5432"4262026-10-01 07:31:55.241 UTC [136] LOG: database system was shut down at 2026-10-01 07:31:55 UTC4272026-10-01 07:31:55.244 UTC [129] LOG: database system is ready to accept connections428/build/postgres4151918893:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-10-01 07:31:55.749 UTC [566] ERROR: relation "goose_db_version" does not exist at character 364712026-10-01 07:31:55.749 UTC [566] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/10/01 07:31:55 OK 20241026095416_initial_model.sql (8.75ms)4732026/10/01 07:31:55 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)4742026/10/01 07:31:55 OK 20251218171726_add_pins.sql (3.53ms)4752026/10/01 07:31:55 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)4762026/10/01 07:31:55 OK 20260905000000_add_claims.sql (3.34ms)4772026/10/01 07:31:55 OK 20260920000000_drop_claims.sql (2.36ms)4782026/10/01 07:31:55 OK 20260923120000_add_pushes.sql (1.25ms)4792026/10/01 07:31:55 goose: successfully migrated database to version: 202609231200004802026/10/01 07:31:55 OK 1_commit_pending_closure.sql (1.74ms)4812026/10/01 07:31:55 OK 2_object_stats_trigger.sql (874.49µs)4822026/10/01 07:31:55 OK 3_commit_push.sql (750.88µs)4832026/10/01 07:31:55 goose: up to current file version: 34842026/10/01 07:31:55 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 07:31:56 INFO lead: released remote=192.0.2.1:12344862026/10/01 07:31:56 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 07:31:56 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.82s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-10-01 07:31:56.531 UTC [576] ERROR: relation "goose_db_version" does not exist at character 364932026-10-01 07:31:56.531 UTC [576] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/10/01 07:31:56 OK 20241026095416_initial_model.sql (7.12ms)4952026/10/01 07:31:56 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)4962026/10/01 07:31:56 OK 20251218171726_add_pins.sql (2.5ms)4972026/10/01 07:31:56 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)4982026/10/01 07:31:56 OK 20260905000000_add_claims.sql (2.19ms)4992026/10/01 07:31:56 OK 20260920000000_drop_claims.sql (1.63ms)5002026/10/01 07:31:56 OK 20260923120000_add_pushes.sql (1.06ms)5012026/10/01 07:31:56 goose: successfully migrated database to version: 202609231200005022026/10/01 07:31:56 OK 1_commit_pending_closure.sql (1.55ms)5032026/10/01 07:31:56 OK 2_object_stats_trigger.sql (715.95µs)5042026/10/01 07:31:56 OK 3_commit_push.sql (748.49µs)5052026/10/01 07:31:56 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestGCTaskStore_StartNew524=== PAUSE TestGCTaskStore_StartNew525=== RUN TestGCTaskStore_DeduplicateSameParams526=== PAUSE TestGCTaskStore_DeduplicateSameParams527=== RUN TestGCTaskStore_ConflictDifferentParams528=== PAUSE TestGCTaskStore_ConflictDifferentParams529=== RUN TestGCTaskStore_GetEmpty530=== PAUSE TestGCTaskStore_GetEmpty531=== RUN TestGCTaskStore_GetReturnsLatest532=== PAUSE TestGCTaskStore_GetReturnsLatest533=== RUN TestGCTaskStore_CompletedAllowsNewTask534=== PAUSE TestGCTaskStore_CompletedAllowsNewTask535=== RUN TestGCTaskStore_PhaseUpdates536=== PAUSE TestGCTaskStore_PhaseUpdates537=== RUN TestGCTaskStore_Fail538=== PAUSE TestGCTaskStore_Fail539=== RUN TestGracefulShutdownDrainsInflight540=== PAUSE TestGracefulShutdownDrainsInflight541=== RUN TestService_healthCheckHandler542=== PAUSE TestService_healthCheckHandler543=== RUN TestService_readinessHandler544=== PAUSE TestService_readinessHandler545=== RUN TestGenerateLandingPage546=== PAUSE TestGenerateLandingPage547=== RUN TestCacheConfigHandlerMaxNarSize548=== PAUSE TestCacheConfigHandlerMaxNarSize549=== RUN TestCreatePendingClosureRejectsOversizedNAR550=== PAUSE TestCreatePendingClosureRejectsOversizedNAR551=== RUN TestNARDeduplicationMetadataUploadBug552=== PAUSE TestNARDeduplicationMetadataUploadBug553=== RUN TestMetricsInventory554=== PAUSE TestMetricsInventory555=== RUN TestService_NativeMTLS556=== PAUSE TestService_NativeMTLS557=== RUN TestServerTLSConfig558=== PAUSE TestServerTLSConfig559=== RUN TestMultipartCleanup560=== PAUSE TestMultipartCleanup561=== RUN TestObjectStatsTrigger562=== PAUSE TestObjectStatsTrigger563=== RUN TestOrphanedObjectsGC564=== PAUSE TestOrphanedObjectsGC565=== RUN TestOrphanedObjectsGCStressTest566=== PAUSE TestOrphanedObjectsGCStressTest567=== RUN TestResurrectedObjectNotDeleted568=== PAUSE TestResurrectedObjectNotDeleted569=== RUN TestCreatePin_ReservedPins570=== PAUSE TestCreatePin_ReservedPins571=== RUN TestParseSingleRange572=== PAUSE TestParseSingleRange573=== RUN TestProxyHeadersOnlyTrustedOnSocket574=== PAUSE TestProxyHeadersOnlyTrustedOnSocket575=== RUN TestIsValidCachePath576=== PAUSE TestIsValidCachePath577=== RUN TestReadProxyNarinfo578=== PAUSE TestReadProxyNarinfo579=== RUN TestReadProxyNarinfoAlreadyDecompressed580=== PAUSE TestReadProxyNarinfoAlreadyDecompressed581=== RUN TestReadProxyNarStreaming582=== PAUSE TestReadProxyNarStreaming583=== RUN TestReadProxy404584=== PAUSE TestReadProxy404585=== RUN TestReadProxyInvalidPath586=== PAUSE TestReadProxyInvalidPath587=== RUN TestReadProxyHead588=== PAUSE TestReadProxyHead589=== RUN TestReadProxyConditionalGet590=== PAUSE TestReadProxyConditionalGet591=== RUN TestReadProxyRootRedirectsToIndexHTML592=== PAUSE TestReadProxyRootRedirectsToIndexHTML593=== RUN TestReadProxyDisabled594=== PAUSE TestReadProxyDisabled595=== RUN TestReadRedirectNar596=== PAUSE TestReadRedirectNar597=== RUN TestReadRedirectKeepsNarinfoProxied598=== PAUSE TestReadRedirectKeepsNarinfoProxied599=== RUN TestReadProxyRangeRequest600=== PAUSE TestReadProxyRangeRequest601=== RUN TestReadRedirectUsesPublicS3URL602=== PAUSE TestReadRedirectUsesPublicS3URL603=== RUN TestPush_OverlappingRootsStoreOneRowPerKey604=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey605=== RUN TestPush_CompleteCommitsEveryRoot606=== PAUSE TestPush_CompleteCommitsEveryRoot607=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit608=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit609=== RUN TestPush_RejectsBadRequests610=== PAUSE TestPush_RejectsBadRequests611=== RUN TestPush_SignsNarinfosOfItsPendingObjects612=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects613=== RUN TestRedundantMultipartUpload614=== PAUSE TestRedundantMultipartUpload615=== RUN TestCompleteMultipartUpload_ErrorButObjectExists616=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists617=== RUN TestCompletedNarNotReofferedAcrossClosures618=== PAUSE TestCompletedNarNotReofferedAcrossClosures619=== RUN TestPresignedUploadRegisteredBeforeCommit620=== PAUSE TestPresignedUploadRegisteredBeforeCommit621=== RUN TestService_Rustfstest622=== PAUSE TestService_Rustfstest623=== RUN TestParseSize624=== PAUSE TestParseSize625=== RUN TestSkippedUploadsHandler626=== PAUSE TestSkippedUploadsHandler627=== RUN TestSystemdListenerNotActivated628--- PASS: TestSystemdListenerNotActivated (0.00s)629=== RUN TestWatchdogBeatsWhenHealthy630--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)631=== RUN TestWatchdogSkipsWhenUnhealthy6322026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6332026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6342026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:31:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"642--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)643=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle644=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle645=== RUN TestProxyWriteTimeout646=== PAUSE TestProxyWriteTimeout647=== RUN TestIsValidUploadKey648=== PAUSE TestIsValidUploadKey649=== RUN TestUploadHandlersRejectInvalidKeys650=== PAUSE TestUploadHandlersRejectInvalidKeys651=== RUN TestUploadHandlersRejectOversizedBody652=== PAUSE TestUploadHandlersRejectOversizedBody653=== RUN TestService_cleanupPendingClosuresHandler654=== PAUSE TestService_cleanupPendingClosuresHandler655=== RUN TestService_createPendingClosureHandler656=== PAUSE TestService_createPendingClosureHandler657=== RUN TestService_verifyS3Integrity658=== PAUSE TestService_verifyS3Integrity659=== RUN TestCompleteMultipartUnregistered660=== PAUSE TestCompleteMultipartUnregistered661=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT662=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT663=== CONT TestService_AuthMiddleware664=== CONT TestCompleteMultipartUpload_ErrorButObjectExists665=== CONT TestReadProxyNarStreaming666=== CONT TestGCTaskStore_StartNew667--- PASS: TestGCTaskStore_StartNew (0.00s)668=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT669=== CONT TestCompleteMultipartUnregistered670=== CONT TestService_verifyS3Integrity671=== CONT TestService_createPendingClosureHandler672=== CONT TestService_cleanupPendingClosuresHandler673=== CONT TestUploadHandlersRejectOversizedBody674=== CONT TestUploadHandlersRejectInvalidKeys675=== CONT TestIsValidUploadKey676=== CONT TestProxyWriteTimeout677=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle678=== CONT TestSkippedUploadsHandler679=== CONT TestParseSize680=== CONT TestService_Rustfstest681=== CONT TestPresignedUploadRegisteredBeforeCommit682=== CONT TestCompletedNarNotReofferedAcrossClosures683=== CONT TestReadProxyNarinfoAlreadyDecompressed684=== CONT TestReadProxyNarinfo685=== CONT TestIsValidCachePath686=== CONT TestProxyHeadersOnlyTrustedOnSocket687=== CONT TestParseSingleRange688=== CONT TestCreatePin_ReservedPins689=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info690=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info691=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal692=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal693=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key694=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key695=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key696=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key697=== RUN TestProxyWriteTimeout/narinfo698=== RUN TestIsValidUploadKey/narinfo699=== PAUSE TestProxyWriteTimeout/narinfo700=== RUN TestProxyWriteTimeout/1_GiB_nar701=== PAUSE TestProxyWriteTimeout/1_GiB_nar702=== CONT TestResurrectedObjectNotDeleted703=== RUN TestProxyWriteTimeout/10_GiB_nar704=== PAUSE TestProxyWriteTimeout/10_GiB_nar705--- PASS: TestParseSize (0.00s)706=== RUN TestParseSingleRange/none707=== RUN TestIsValidCachePath/narinfo708=== RUN TestProxyWriteTimeout/unknown_size7092026/10/01 07:31:56 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000710=== PAUSE TestProxyWriteTimeout/unknown_size711=== PAUSE TestIsValidCachePath/narinfo712=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars713=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars714=== CONT TestOrphanedObjectsGCStressTest715=== PAUSE TestParseSingleRange/none716=== PAUSE TestIsValidUploadKey/narinfo717=== CONT TestOrphanedObjectsGC718=== RUN TestParseSingleRange/unknown_unit719=== PAUSE TestParseSingleRange/unknown_unit720=== RUN TestParseSingleRange/multi-range_ignored721=== PAUSE TestParseSingleRange/multi-range_ignored722=== RUN TestParseSingleRange/malformed_no_dash723=== PAUSE TestParseSingleRange/malformed_no_dash724=== RUN TestParseSingleRange/malformed_both_empty725=== PAUSE TestParseSingleRange/malformed_both_empty726=== RUN TestParseSingleRange/malformed_end_before_start727=== PAUSE TestParseSingleRange/malformed_end_before_start728=== RUN TestIsValidCachePath/nar_zst729=== PAUSE TestIsValidCachePath/nar_zst730=== RUN TestIsValidCachePath/nar_xz731=== PAUSE TestIsValidCachePath/nar_xz732=== RUN TestIsValidCachePath/nar_bz2733=== PAUSE TestIsValidCachePath/nar_bz2734=== RUN TestIsValidUploadKey/nar_zst735=== RUN TestParseSingleRange/closed736=== PAUSE TestIsValidUploadKey/nar_zst737=== RUN TestIsValidUploadKey/nar_xz738=== PAUSE TestIsValidUploadKey/nar_xz739=== RUN TestIsValidUploadKey/nar_plain740=== PAUSE TestIsValidUploadKey/nar_plain741=== PAUSE TestParseSingleRange/closed742=== RUN TestParseSingleRange/open-ended743=== PAUSE TestParseSingleRange/open-ended744=== RUN TestParseSingleRange/end_clamped_to_size745=== PAUSE TestParseSingleRange/end_clamped_to_size746=== RUN TestIsValidCachePath/nar_uncompressed747=== PAUSE TestIsValidCachePath/nar_uncompressed748=== RUN TestIsValidCachePath/ls749=== PAUSE TestIsValidCachePath/ls750=== RUN TestIsValidCachePath/log751=== PAUSE TestIsValidCachePath/log752=== RUN TestIsValidCachePath/realisation753=== PAUSE TestIsValidCachePath/realisation754=== RUN TestIsValidCachePath/nix-cache-info755=== PAUSE TestIsValidCachePath/nix-cache-info756=== RUN TestIsValidCachePath/index.html757=== PAUSE TestIsValidCachePath/index.html758=== RUN TestIsValidUploadKey/listing759=== RUN TestParseSingleRange/suffix760=== PAUSE TestParseSingleRange/suffix761=== RUN TestParseSingleRange/suffix_exceeds_size762=== PAUSE TestParseSingleRange/suffix_exceeds_size763=== RUN TestParseSingleRange/single_byte764=== PAUSE TestParseSingleRange/single_byte765=== RUN TestParseSingleRange/start_past_EOF766=== PAUSE TestParseSingleRange/start_past_EOF767=== RUN TestParseSingleRange/start_far_past_EOF768=== PAUSE TestParseSingleRange/start_far_past_EOF769=== RUN TestIsValidCachePath/traversal_parent770=== PAUSE TestIsValidCachePath/traversal_parent771=== RUN TestIsValidCachePath/traversal_in_middle772=== PAUSE TestIsValidCachePath/traversal_in_middle773=== RUN TestIsValidCachePath/invalid_char_e774=== PAUSE TestIsValidCachePath/invalid_char_e775=== RUN TestIsValidCachePath/invalid_char_u776=== PAUSE TestIsValidCachePath/invalid_char_u777=== PAUSE TestIsValidUploadKey/listing778=== CONT TestObjectStatsTrigger779=== RUN TestIsValidCachePath/random_path780=== PAUSE TestIsValidCachePath/random_path781=== RUN TestIsValidCachePath/empty782=== PAUSE TestIsValidCachePath/empty783=== RUN TestIsValidUploadKey/build_log784=== PAUSE TestIsValidUploadKey/build_log785--- PASS: TestSkippedUploadsHandler (0.01s)786=== CONT TestMultipartCleanup787=== RUN TestIsValidCachePath/leading_slash788=== PAUSE TestIsValidCachePath/leading_slash789=== RUN TestIsValidUploadKey/build_log_home-manager_file790=== PAUSE TestIsValidUploadKey/build_log_home-manager_file791=== RUN TestIsValidCachePath/wrong_extension792=== PAUSE TestIsValidCachePath/wrong_extension793=== RUN TestIsValidUploadKey/build_log_plus_in_name794=== PAUSE TestIsValidUploadKey/build_log_plus_in_name795=== RUN TestIsValidCachePath/short_hash796=== PAUSE TestIsValidCachePath/short_hash797=== RUN TestIsValidUploadKey/build_log_question_mark798=== PAUSE TestIsValidUploadKey/build_log_question_mark799=== RUN TestIsValidUploadKey/build_log_equals800=== CONT TestServerTLSConfig801=== RUN TestServerTLSConfig/no_client_CA802=== PAUSE TestIsValidUploadKey/build_log_equals803=== RUN TestIsValidUploadKey/realisation804=== PAUSE TestIsValidUploadKey/realisation805=== RUN TestIsValidUploadKey/realisation_plus_in_output806=== PAUSE TestIsValidUploadKey/realisation_plus_in_output807=== RUN TestIsValidUploadKey/nix-cache-info808=== PAUSE TestIsValidUploadKey/nix-cache-info809=== PAUSE TestServerTLSConfig/no_client_CA810=== RUN TestIsValidUploadKey/index.html811=== PAUSE TestIsValidUploadKey/index.html812=== RUN TestIsValidUploadKey/narinfo_key,_nar_type813=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type814=== RUN TestIsValidUploadKey/nar_key,_narinfo_type815=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type816=== RUN TestIsValidUploadKey/listing_key,_narinfo_type817=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type818=== RUN TestIsValidUploadKey/traversal819=== PAUSE TestIsValidUploadKey/traversal820=== RUN TestIsValidUploadKey/traversal_nar821=== PAUSE TestIsValidUploadKey/traversal_nar822=== RUN TestIsValidUploadKey/absolute823=== PAUSE TestIsValidUploadKey/absolute824=== RUN TestIsValidUploadKey/empty_key825=== PAUSE TestIsValidUploadKey/empty_key826=== RUN TestIsValidUploadKey/unknown_type827=== PAUSE TestIsValidUploadKey/unknown_type828=== RUN TestServerTLSConfig/missing_CA_file829=== PAUSE TestServerTLSConfig/missing_CA_file830=== RUN TestServerTLSConfig/not_a_PEM_file831=== PAUSE TestServerTLSConfig/not_a_PEM_file832=== CONT TestMetricsInventory833=== CONT TestService_NativeMTLS8342026/10/01 07:31:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37917/oidc8352026-10-01 07:31:57.046 UTC [638] ERROR: relation "goose_db_version" does not exist at character 368362026-10-01 07:31:57.046 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026-10-01 07:31:57.046 UTC [639] ERROR: relation "goose_db_version" does not exist at character 368382026-10-01 07:31:57.046 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026-10-01 07:31:57.052 UTC [642] ERROR: relation "goose_db_version" does not exist at character 368402026-10-01 07:31:57.052 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC841=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure842=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure843=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart844=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart845=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts846=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts847=== CONT TestNARDeduplicationMetadataUploadBug8482026-10-01 07:31:57.094 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368492026-10-01 07:31:57.094 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026-10-01 07:31:57.098 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368512026-10-01 07:31:57.098 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8522026-10-01 07:31:57.099 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368532026-10-01 07:31:57.099 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026/10/01 07:31:57 OK 20241026095416_initial_model.sql (35.23ms)8552026/10/01 07:31:57 OK 20241026095416_initial_model.sql (33.92ms)8562026-10-01 07:31:57.116 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368572026-10-01 07:31:57.116 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026/10/01 07:31:57 OK 20241026095416_initial_model.sql (39.55ms)8592026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)8602026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)8612026-10-01 07:31:57.120 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368622026-10-01 07:31:57.120 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8632026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)8642026/10/01 07:31:57 OK 20251218171726_add_pins.sql (5.41ms)8652026/10/01 07:31:57 OK 20251218171726_add_pins.sql (6.11ms)8662026-10-01 07:31:57.126 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368672026-10-01 07:31:57.126 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8682026-10-01 07:31:57.127 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368692026-10-01 07:31:57.127 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026/10/01 07:31:57 OK 20251218171726_add_pins.sql (5.31ms)8712026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (6.43ms)8722026/10/01 07:31:57 OK 20241026095416_initial_model.sql (14.14ms)8732026/10/01 07:31:57 OK 20241026095416_initial_model.sql (14.18ms)8742026/10/01 07:31:57 OK 20241026095416_initial_model.sql (14.2ms)8752026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (5.64ms)8762026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (5.24ms)8772026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)8782026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)8792026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)8802026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.8ms)8812026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.24ms)8822026/10/01 07:31:57 OK 20241026095416_initial_model.sql (13.31ms)8832026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (4.5ms)8842026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (5.85ms)8852026/10/01 07:31:57 OK 20260905000000_add_claims.sql (7.27ms)8862026/10/01 07:31:57 OK 20251218171726_add_pins.sql (6.92ms)8872026/10/01 07:31:57 OK 20251218171726_add_pins.sql (6.83ms)8882026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)8892026-10-01 07:31:57.141 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368902026-10-01 07:31:57.141 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8912026/10/01 07:31:57 OK 20251218171726_add_pins.sql (8.39ms)8922026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.22ms)8932026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (4.29ms)8942026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200008952026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (4.36ms)8962026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200008972026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (3.43ms)8982026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200008992026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (6.99ms)9002026/10/01 07:31:57 OK 20251218171726_add_pins.sql (6.72ms)9012026/10/01 07:31:57 OK 20241026095416_initial_model.sql (18.26ms)9022026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.94ms)9032026/10/01 07:31:57 OK 1_commit_pending_closure.sql (4.2ms)9042026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (7.75ms)9052026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (7.93ms)9062026/10/01 07:31:57 OK 20241026095416_initial_model.sql (17.2ms)9072026/10/01 07:31:57 OK 20241026095416_initial_model.sql (16.32ms)9082026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.12ms)9092026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.01ms)9102026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)9112026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.44ms)9122026/10/01 07:31:57 OK 2_object_stats_trigger.sql (3.39ms)9132026-10-01 07:31:57.154 UTC [658] ERROR: relation "goose_db_version" does not exist at character 369142026-10-01 07:31:57.154 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026-10-01 07:31:57.156 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369162026-10-01 07:31:57.156 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026/10/01 07:31:57 OK 3_commit_push.sql (11.59ms)9182026/10/01 07:31:57 goose: up to current file version: 39192026/10/01 07:31:57 OK 20260905000000_add_claims.sql (13.67ms)9202026/10/01 07:31:57 OK 2_object_stats_trigger.sql (11.81ms)9212026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (14.85ms)9222026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (12.12ms)9232026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (12.44ms)9242026/10/01 07:31:57 OK 3_commit_push.sql (14.08ms)9252026/10/01 07:31:57 goose: up to current file version: 39262026/10/01 07:31:57 OK 20260905000000_add_claims.sql (16.87ms)9272026/10/01 07:31:57 OK 20251218171726_add_pins.sql (15.53ms)9282026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (15.03ms)9292026/10/01 07:31:57 OK 3_commit_push.sql (5.37ms)9302026/10/01 07:31:57 goose: up to current file version: 39312026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (10.7ms)9322026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (7.28ms)9332026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200009342026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (9.26ms)9352026/10/01 07:31:57 OK 20251218171726_add_pins.sql (13.61ms)9362026/10/01 07:31:57 OK 20251218171726_add_pins.sql (13.86ms)9372026/10/01 07:31:57 OK 20260905000000_add_claims.sql (13.91ms)9382026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (4.58ms)9392026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200009402026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.55ms)9412026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (11.42ms)9422026/10/01 07:31:57 OK 20241026095416_initial_model.sql (27.13ms)9432026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (4.88ms)9442026/10/01 07:31:57 OK 1_commit_pending_closure.sql (4.23ms)9452026/10/01 07:31:57 OK 2_object_stats_trigger.sql (4.29ms)9462026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (6.44ms)9472026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200009482026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (4.28ms)9492026/10/01 07:31:57 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"950--- PASS: TestService_AuthMiddleware (0.36s)951=== CONT TestCreatePendingClosureRejectsOversizedNAR9522026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (7.05ms)954--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)955=== CONT TestCacheConfigHandlerMaxNarSize956--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)957=== CONT TestGenerateLandingPage9582026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.5ms)9592026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (3.28ms)9602026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200009612026/10/01 07:31:57 OK 20260905000000_add_claims.sql (6.69ms)9622026/10/01 07:31:57 OK 3_commit_push.sql (2.44ms)9632026/10/01 07:31:57 goose: up to current file version: 39642026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (9.49ms)9652026/10/01 07:31:57 OK 20241026095416_initial_model.sql (19.31ms)966--- PASS: TestGenerateLandingPage (0.00s)9672026/10/01 07:31:57 OK 3_commit_push.sql (2.12ms)968=== CONT TestService_readinessHandler9692026/10/01 07:31:57 goose: up to current file version: 39702026/10/01 07:31:57 OK 1_commit_pending_closure.sql (4.68ms)9712026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.95ms)9722026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.32ms)9732026/10/01 07:31:57 OK 20251218171726_add_pins.sql (5.91ms)9742026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)9752026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (4.24ms)9762026/10/01 07:31:57 OK 2_object_stats_trigger.sql (4.1ms)9772026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures9782026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (12ms)9792026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200009802026/10/01 07:31:57 OK 20260905000000_add_claims.sql (15.9ms)9812026/10/01 07:31:57 OK 2_object_stats_trigger.sql (13.38ms)9822026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (13.96ms)9832026/10/01 07:31:57 OK 3_commit_push.sql (14.08ms)9842026/10/01 07:31:57 goose: up to current file version: 39852026/10/01 07:31:57 OK 20241026095416_initial_model.sql (30.23ms)9862026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (17.28ms)9872026/10/01 07:31:57 OK 20251218171726_add_pins.sql (16.35ms)9882026/10/01 07:31:57 OK 3_commit_push.sql (5.13ms)9892026/10/01 07:31:57 goose: up to current file version: 39902026/10/01 07:31:57 OK 1_commit_pending_closure.sql (6.18ms)9912026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (6.83ms)9922026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (6.44ms)9932026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200009942026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.77ms)9952026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (3.53ms)9962026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.8ms)9972026/10/01 07:31:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.93ms)9992026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000010002026/10/01 07:31:57 OK 3_commit_push.sql (1.79ms)10012026/10/01 07:31:57 goose: up to current file version: 310022026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (6.42ms)10032026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.82ms)10042026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.66ms)10052026/10/01 07:31:57 OK 20251218171726_add_pins.sql (4.31ms)10062026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.81ms)10072026/10/01 07:31:57 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst10082026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.25ms)10092026/10/01 07:31:57 goose: successfully migrated database to version: 202609231200001010--- PASS: TestCompleteMultipartUnregistered (0.39s)1011=== CONT TestService_healthCheckHandler10122026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.89ms)10132026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.71ms)10142026/10/01 07:31:57 OK 3_commit_push.sql (1.59ms)10152026/10/01 07:31:57 goose: up to current file version: 310162026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.52ms)10172026-10-01 07:31:57.220 UTC [665] ERROR: relation "goose_db_version" does not exist at character 3610182026-10-01 07:31:57.220 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10192026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.7ms)10202026/10/01 07:31:57 OK 1_commit_pending_closure.sql (4.02ms)10212026/10/01 07:31:57 OK 3_commit_push.sql (2.28ms)10222026/10/01 07:31:57 goose: up to current file version: 310232026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (6.87ms)10242026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.53ms)10252026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000010262026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.22ms)1027--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)1028=== CONT TestGracefulShutdownDrainsInflight10292026-10-01 07:31:57.224 UTC [666] ERROR: relation "goose_db_version" does not exist at character 3610302026-10-01 07:31:57.224 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10312026/10/01 07:31:57 INFO Starting HTTP server address=127.0.0.1:3712310322026/10/01 07:31:57 INFO Shutdown signal received, draining in-flight requests timeout=10s10332026-10-01 07:31:57.225 UTC [668] ERROR: relation "goose_db_version" does not exist at character 3610342026-10-01 07:31:57.225 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10352026/10/01 07:31:57 OK 3_commit_push.sql (1.86ms)10362026/10/01 07:31:57 goose: up to current file version: 310372026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.43ms)10382026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.78ms)10392026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.04ms)10402026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.83ms)10412026/10/01 07:31:57 OK 3_commit_push.sql (1.59ms)10422026/10/01 07:31:57 goose: up to current file version: 310432026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.76ms)10442026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000010452026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures10462026-10-01 07:31:57.235 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3610472026-10-01 07:31:57.235 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10482026-10-01 07:31:57.235 UTC [671] ERROR: relation "goose_db_version" does not exist at character 3610492026-10-01 07:31:57.235 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10502026-10-01 07:31:57.236 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3610512026-10-01 07:31:57.236 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10522026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.65ms)10532026/10/01 07:31:57 OK 20241026095416_initial_model.sql (10.81ms)10542026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.29ms)10552026/10/01 07:31:57 OK 3_commit_push.sql (1.46ms)10562026/10/01 07:31:57 goose: up to current file version: 310572026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)10582026-10-01 07:31:57.241 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3610592026-10-01 07:31:57.241 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026-10-01 07:31:57.243 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3610612026-10-01 07:31:57.243 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10622026-10-01 07:31:57.244 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3610632026-10-01 07:31:57.244 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10642026/10/01 07:31:57 OK 20251218171726_add_pins.sql (5.47ms)10652026/10/01 07:31:57 OK 20241026095416_initial_model.sql (13ms)10662026/10/01 07:31:57 OK 20241026095416_initial_model.sql (13.14ms)10672026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)10682026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)10692026-10-01 07:31:57.249 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3610702026-10-01 07:31:57.249 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10712026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.99ms)10722026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.43ms)10732026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (6.27ms)10742026/10/01 07:31:57 OK 20241026095416_initial_model.sql (10.18ms)10752026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)10762026-10-01 07:31:57.253 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3610772026-10-01 07:31:57.253 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10782026/10/01 07:31:57 OK 20251218171726_add_pins.sql (4.23ms)10792026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)10802026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.41ms)10812026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.32ms)10822026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)10832026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.17ms)10842026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)10852026/10/01 07:31:57 OK 20241026095416_initial_model.sql (10.04ms)10862026/10/01 07:31:57 OK 20241026095416_initial_model.sql (12.32ms)10872026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)10882026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.09ms)10892026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.45ms)10902026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.77ms)10912026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)10922026/10/01 07:31:57 OK 20241026095416_initial_model.sql (10.79ms)10932026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)10942026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)10952026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.82ms)10962026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)10972026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000010982026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.14ms)10992026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.41ms)11002026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.65ms)11012026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)11022026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.87ms)11032026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (1.95ms)11042026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.68ms)11052026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.19ms)11062026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011072026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.55ms)11082026/10/01 07:31:57 OK 20260905000000_add_claims.sql (2.9ms)11092026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.29ms)11102026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.62ms)1111--- PASS: TestReadProxyNarStreaming (0.44s)1112=== CONT TestGCTaskStore_Fail1113--- PASS: TestGCTaskStore_Fail (0.00s)1114=== CONT TestGCTaskStore_PhaseUpdates1115--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)11162026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.39ms)1117=== CONT TestReadProxyRangeRequest11182026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)11192026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.43ms)11202026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011212026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.11ms)11222026/10/01 07:31:57 OK 20241026095416_initial_model.sql (10.94ms)11232026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.08ms)11242026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011252026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.59ms)11262026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.52ms)11272026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.54ms)11282026/10/01 07:31:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11292026/10/01 07:31:57 OK 3_commit_push.sql (1.5ms)11302026/10/01 07:31:57 goose: up to current file version: 311312026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)11322026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)11332026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)11342026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.58ms)11352026/10/01 07:31:57 OK 1_commit_pending_closure.sql (1.72ms)11362026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)11372026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.1ms)11382026/10/01 07:31:57 OK 20260905000000_add_claims.sql (2.68ms)11392026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.53ms)11402026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011412026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)11422026/10/01 07:31:57 OK 3_commit_push.sql (1.43ms)11432026/10/01 07:31:57 goose: up to current file version: 311442026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.38ms)11452026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.01ms)11462026/10/01 07:31:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWZiNzU5NzItZWYzNC00NWUyLWIzOTItZjU4NDE2ZTIyN2M1LjdlZDI2MDE4LWFmMDUtNGVkNS1hYjkzLWNiMDAwNzgwMzNmOHgxNzkwODM5OTE3MjQ2MzI2NDI411472026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.27ms)11482026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures11492026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.38ms)11502026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.24ms)11512026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.16ms)11522026/10/01 07:31:57 OK 3_commit_push.sql (9.15ms)11532026/10/01 07:31:57 goose: up to current file version: 311542026/10/01 07:31:57 OK 20260905000000_add_claims.sql (11.62ms)11552026/10/01 07:31:57 OK 20251218171726_add_pins.sql (11.12ms)11562026/10/01 07:31:57 OK 2_object_stats_trigger.sql (9.79ms)11572026/10/01 07:31:57 OK 3_commit_push.sql (10.35ms)11582026/10/01 07:31:57 goose: up to current file version: 311592026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (9.65ms)11602026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (10.1ms)11612026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011622026/10/01 07:31:57 OK 20260905000000_add_claims.sql (12.15ms)11632026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (10.45ms)11642026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.57ms)11652026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)11662026/10/01 07:31:57 OK 3_commit_push.sql (2.27ms)11672026/10/01 07:31:57 goose: up to current file version: 311682026/10/01 07:31:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWZiNzU5NzItZWYzNC00NWUyLWIzOTItZjU4NDE2ZTIyN2M1LjdlZDI2MDE4LWFmMDUtNGVkNS1hYjkzLWNiMDAwNzgwMzNmOHgxNzkwODM5OTE3MjQ2MzI2NDI4 parts=11169--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.46s)1170=== CONT TestGCTaskStore_CompletedAllowsNewTask1171--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1172=== CONT TestGCTaskStore_GetReturnsLatest1173--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1174=== CONT TestRedundantMultipartUpload11752026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.78ms)11762026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (3.36ms)11772026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011782026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (4.26ms)11792026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.91ms)11802026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011812026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.98ms)11822026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.58ms)11832026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.45ms)11842026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.25ms)11852026/10/01 07:31:57 OK 1_commit_pending_closure.sql (1.97ms)11862026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.26ms)11872026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000011882026/10/01 07:31:57 OK 2_object_stats_trigger.sql (925.77µs)11892026/10/01 07:31:57 OK 3_commit_push.sql (1.56ms)11902026/10/01 07:31:57 goose: up to current file version: 311912026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.54ms)11922026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures1193--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1194=== CONT TestGCTaskStore_GetEmpty11952026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.45ms)1196--- PASS: TestGCTaskStore_GetEmpty (0.00s)1197=== CONT TestGCTaskStore_ConflictDifferentParams11982026/10/01 07:31:57 OK 3_commit_push.sql (1.51ms)1199--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)12002026/10/01 07:31:57 goose: up to current file version: 31201=== CONT TestPush_SignsNarinfosOfItsPendingObjects12022026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.77ms)12032026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.23ms)12042026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.82ms)12052026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000012062026/10/01 07:31:57 OK 3_commit_push.sql (1.12ms)12072026/10/01 07:31:57 goose: up to current file version: 312082026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.4ms)12092026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.06ms)12102026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000012112026/10/01 07:31:57 OK 1_commit_pending_closure.sql (1.65ms)12122026/10/01 07:31:57 OK 3_commit_push.sql (927.62µs)12132026/10/01 07:31:57 goose: up to current file version: 312142026/10/01 07:31:57 OK 2_object_stats_trigger.sql (949.34µs)12152026/10/01 07:31:57 OK 1_commit_pending_closure.sql (1.87ms)12162026/10/01 07:31:57 OK 3_commit_push.sql (1.26ms)12172026/10/01 07:31:57 goose: up to current file version: 312182026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.36ms)12192026/10/01 07:31:57 OK 3_commit_push.sql (1.79ms)12202026/10/01 07:31:57 goose: up to current file version: 312212026-10-01 07:31:57.311 UTC [684] ERROR: relation "goose_db_version" does not exist at character 3612222026-10-01 07:31:57.311 UTC [684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12232026/10/01 07:31:57 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12242026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures1225--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.49s)1226=== CONT TestGCTaskStore_DeduplicateSameParams1227--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1228=== CONT TestPush_RejectsBadRequests1229--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1230=== CONT TestPinProtectsFromGC12312026-10-01 07:31:57.324 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3612322026-10-01 07:31:57.324 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12332026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.32ms)12342026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)12352026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures12362026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures12372026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures12382026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.98ms)12392026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.96ms)12402026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.44ms)12412026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.54ms)12422026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)12432026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.15ms)12442026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.34ms)12452026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.97ms)12462026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000012472026/10/01 07:31:57 OK 1_commit_pending_closure.sql (1.75ms)12482026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)12492026/10/01 07:31:57 OK 2_object_stats_trigger.sql (996.02µs)12502026/10/01 07:31:57 INFO Received cleanup request method=DELETE path=/api/pending_closures12512026/10/01 07:31:57 OK 3_commit_push.sql (1.33ms)12522026/10/01 07:31:57 goose: up to current file version: 312532026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.32ms)12542026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.36ms)12552026/10/01 07:31:57 INFO Aborted multipart uploads count=012562026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.61ms)12572026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000012582026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures12592026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.22ms)12602026/10/01 07:31:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12612026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.28ms)12622026/10/01 07:31:57 OK 3_commit_push.sql (1.18ms)12632026/10/01 07:31:57 goose: up to current file version: 312642026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures12652026/10/01 07:31:57 INFO Received cleanup request method=DELETE path=/api/pending_closures12662026/10/01 07:31:57 INFO Aborted multipart uploads count=112672026/10/01 07:31:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12682026-10-01 07:31:57.463 UTC [656] ERROR: Closure does not exist: id=112692026-10-01 07:31:57.463 UTC [656] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12702026-10-01 07:31:57.463 UTC [656] STATEMENT: -- name: CommitPendingClosure :exec1271 SELECT commit_pending_closure($1::bigint)1272 1273--- PASS: TestService_cleanupPendingClosuresHandler (0.64s)1274=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit12752026/10/01 07:31:57 INFO Starting HTTP server address=127.0.0.1:4414912762026/10/01 07:31:57 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3368966632/001/proxy.sock12772026/10/01 07:31:57 WARN mTLS auth: subject not in bound subjects subject="CN=someone"12782026-10-01 07:31:57.488 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612792026-10-01 07:31:57.488 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12802026-10-01 07:31:57.488 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3612812026-10-01 07:31:57.488 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12822026-10-01 07:31:57.488 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3612832026-10-01 07:31:57.488 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12842026/10/01 07:31:57 INFO Shutdown signal received, draining in-flight requests timeout=10s1285--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.65s)1286=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12872026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures12882026-10-01 07:31:57.501 UTC [697] ERROR: relation "goose_db_version" does not exist at character 3612892026-10-01 07:31:57.501 UTC [697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026-10-01 07:31:57.502 UTC [698] ERROR: relation "goose_db_version" does not exist at character 3612912026-10-01 07:31:57.502 UTC [698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12922026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.07ms)12932026/10/01 07:31:57 OK 20241026095416_initial_model.sql (8.8ms)12942026/10/01 07:31:57 OK 20241026095416_initial_model.sql (8.72ms)12952026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)12962026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)12972026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)12982026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.56ms)12992026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.29ms)13002026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.11ms)13012026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)13022026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)13032026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)13042026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.62ms)13052026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.99ms)13062026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.25ms)13072026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.46ms)13082026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.48ms)13092026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.49ms)13102026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)13112026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.38ms)13122026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)13132026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.2ms)13142026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000013152026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.16ms)13162026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.58ms)13172026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.93ms)13182026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000013192026/10/01 07:31:57 OK 20251218171726_add_pins.sql (4.11ms)13202026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.88ms)13212026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)13222026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (5.11ms)13232026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000013242026/10/01 07:31:57 OK 1_commit_pending_closure.sql (5.19ms)13252026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.69ms)13262026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)13272026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.52ms)13282026/10/01 07:31:57 OK 3_commit_push.sql (1.31ms)13292026/10/01 07:31:57 goose: up to current file version: 313302026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.08ms)13312026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.43ms)13322026/10/01 07:31:57 OK 3_commit_push.sql (1.73ms)13332026/10/01 07:31:57 goose: up to current file version: 313342026/10/01 07:31:57 OK 20260905000000_add_claims.sql (2.97ms)13352026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.82ms)13362026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.33ms)13372026/10/01 07:31:57 OK 3_commit_push.sql (1.35ms)13382026/10/01 07:31:57 goose: up to current file version: 313392026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.12ms)13402026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.98ms)13412026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000013422026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.66ms)13432026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000013442026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.1ms)13452026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.58ms)13462026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.2ms)13472026/10/01 07:31:57 OK 3_commit_push.sql (987.86µs)13482026/10/01 07:31:57 goose: up to current file version: 313492026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.42ms)13502026/10/01 07:31:57 OK 3_commit_push.sql (1.52ms)13512026/10/01 07:31:57 goose: up to current file version: 31352--- PASS: TestObjectStatsTrigger (0.55s)1353=== CONT TestPush_CompleteCommitsEveryRoot13542026/10/01 07:31:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13552026/10/01 07:31:57 WARN Refused reserved pin name=worker-x86_64-linux13562026/10/01 07:31:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13572026/10/01 07:31:57 INFO Received create pin request method=POST path=/api/pins/my-app13582026/10/01 07:31:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1359--- PASS: TestCreatePin_ReservedPins (0.74s)1360=== CONT TestGCSweepDeliversEachKeyOnce13612026-10-01 07:31:57.583 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3613622026-10-01 07:31:57.583 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/10/01 07:31:57 OK 20241026095416_initial_model.sql (11.58ms)13642026-10-01 07:31:57.600 UTC [704] ERROR: relation "goose_db_version" does not exist at character 3613652026-10-01 07:31:57.600 UTC [704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13662026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)13672026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures13682026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.94ms)13692026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)13702026/10/01 07:31:57 OK 20260905000000_add_claims.sql (2.66ms)13712026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.47ms)13722026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.68ms)13732026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.15ms)13742026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000013752026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)13762026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.34ms)13772026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.45ms)13782026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.27ms)1379--- PASS: TestResurrectedObjectNotDeleted (0.64s)1380=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13812026/10/01 07:31:57 OK 3_commit_push.sql (1.08ms)13822026/10/01 07:31:57 goose: up to current file version: 313832026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)13842026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.54ms)13852026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.87ms)13862026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.08ms)13872026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000013882026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.13ms)13892026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.2ms)13902026/10/01 07:31:57 OK 3_commit_push.sql (1.53ms)13912026/10/01 07:31:57 goose: up to current file version: 313922026-10-01 07:31:57.642 UTC [707] ERROR: relation "goose_db_version" does not exist at character 3613932026-10-01 07:31:57.642 UTC [707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1394--- PASS: TestMetricsInventory (0.65s)1395=== CONT TestTombstonedObjectOfferedWithoutWaiting13962026/10/01 07:31:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13972026/10/01 07:31:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1398--- PASS: TestService_NativeMTLS (0.65s)1399=== CONT TestReadRedirectUsesPublicS3URL14002026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.11ms)14012026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (988.97µs)14022026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.76ms)14032026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)14042026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.15ms)14052026-10-01 07:31:57.671 UTC [712] ERROR: relation "goose_db_version" does not exist at character 3614062026-10-01 07:31:57.671 UTC [712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14072026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.62ms)14082026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.91ms)14092026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000014102026/10/01 07:31:57 OK 1_commit_pending_closure.sql (1.49ms)14112026/10/01 07:31:57 OK 2_object_stats_trigger.sql (919.36µs)14122026/10/01 07:31:57 OK 3_commit_push.sql (967.02µs)14132026/10/01 07:31:57 goose: up to current file version: 31414--- PASS: TestService_Rustfstest (0.70s)1415=== CONT TestGCSweepSkipsPendingObjects14162026/10/01 07:31:57 OK 20241026095416_initial_model.sql (20.84ms)14172026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (4.29ms)14182026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.24ms)14192026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)14202026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.67ms)14212026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.69ms)14222026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.21ms)14232026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000014242026/10/01 07:31:57 INFO Received cleanup request method=DELETE path=/api/pending_closures14252026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.4ms)1426--- PASS: TestReadProxyNarinfo (0.74s)1427=== CONT TestDeduplicatedObjectsRecordedAsPending14282026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.82ms)14292026/10/01 07:31:57 INFO Aborted multipart uploads count=114302026/10/01 07:31:57 OK 3_commit_push.sql (1.57ms)14312026/10/01 07:31:57 goose: up to current file version: 314322026-10-01 07:31:57.729 UTC [715] ERROR: relation "goose_db_version" does not exist at character 3614332026-10-01 07:31:57.729 UTC [715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1434--- PASS: TestMultipartCleanup (0.74s)1435=== CONT TestPushDedupSurvivesConcurrentGC14362026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.98ms)14372026/10/01 07:31:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14382026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)14392026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.37ms)14402026-10-01 07:31:57.755 UTC [721] ERROR: relation "goose_db_version" does not exist at character 3614412026-10-01 07:31:57.755 UTC [721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14422026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)14432026-10-01 07:31:57.756 UTC [722] ERROR: relation "goose_db_version" does not exist at character 3614442026-10-01 07:31:57.756 UTC [722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14452026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.35ms)14462026/10/01 07:31:57 WARN readiness check failed error="closed pool"14472026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.54ms)1448--- PASS: TestService_readinessHandler (0.57s)1449=== CONT TestCacheStatsHandler14502026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.14ms)14512026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000014522026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.77ms)14532026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.51ms)14542026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.47ms)14552026/10/01 07:31:57 OK 3_commit_push.sql (1.72ms)14562026/10/01 07:31:57 goose: up to current file version: 314572026/10/01 07:31:57 OK 20241026095416_initial_model.sql (17.61ms)14582026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (10.35ms)14592026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.15ms)14602026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)1461=== NAME TestNARDeduplicationMetadataUploadBug14622026/10/01 07:31:57 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YWZiNzU5NzItZWYzNC00NWUyLWIzOTItZjU4NDE2ZTIyN2M1LjdmYTE5NDliLWQ1YmYtNDhiOC1iZDEyLTM1OWU1NjE0ZmFkOHgxNzkwODM5OTE3MzQxNDc4OTI5 parts=101463 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3094559875/001/store/r1gw4dzw01bvzcvw57n65gr6lx00zyi5-file1.txt14642026/10/01 07:31:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1465--- PASS: TestService_healthCheckHandler (0.57s)1466=== CONT TestGCMetrics14672026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.82ms)14682026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)14692026/10/01 07:31:57 INFO Completed upload id=114702026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.66ms)14712026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)14722026/10/01 07:31:57 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014732026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures14742026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.2ms)14752026-10-01 07:31:57.795 UTC [761] ERROR: relation "goose_db_version" does not exist at character 3614762026-10-01 07:31:57.795 UTC [761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14772026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.3ms)14782026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.03ms)14792026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000014802026/10/01 07:31:57 INFO Starting cleanup of old closures method=DELETE path=/api/closures14812026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.43ms)14822026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.11ms)14832026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.13ms)14842026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (3.33ms)14852026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000014862026/10/01 07:31:57 OK 3_commit_push.sql (1.79ms)14872026/10/01 07:31:57 goose: up to current file version: 314882026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.54ms)14892026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.5ms)14902026/10/01 07:31:57 OK 3_commit_push.sql (1.4ms)14912026/10/01 07:31:57 goose: up to current file version: 314922026/10/01 07:31:57 INFO Aborted multipart uploads count=014932026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.57ms)14942026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)14952026/10/01 07:31:57 INFO Received push request method=POST path=/api/pushes14962026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.55ms)14972026/10/01 07:31:57 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=014982026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.71ms)14992026/10/01 07:31:57 INFO Vacuumed table table=pending_closures15002026/10/01 07:31:57 INFO Vacuumed table table=pending_objects15012026/10/01 07:31:57 OK 20260905000000_add_claims.sql (4.72ms)15022026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.58ms)15032026/10/01 07:31:57 INFO Vacuumed table table=multipart_uploads15042026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.79ms)15052026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000015062026/10/01 07:31:57 OK 1_commit_pending_closure.sql (1.64ms)15072026/10/01 07:31:57 INFO Vacuumed table table=closures15082026/10/01 07:31:57 OK 2_object_stats_trigger.sql (985.68µs)15092026/10/01 07:31:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15102026/10/01 07:31:57 INFO Vacuumed table table=objects15112026/10/01 07:31:57 INFO Signed narinfos id=1 count=11512--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.54s)1513=== CONT TestGCBugBareHashReferences15142026/10/01 07:31:57 OK 3_commit_push.sql (1.64ms)15152026/10/01 07:31:57 goose: up to current file version: 315162026-10-01 07:31:57.844 UTC [784] ERROR: relation "goose_db_version" does not exist at character 3615172026-10-01 07:31:57.844 UTC [784] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15182026/10/01 07:31:57 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015192026-10-01 07:31:57.847 UTC [785] ERROR: relation "goose_db_version" does not exist at character 3615202026-10-01 07:31:57.847 UTC [785] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1521--- PASS: TestService_createPendingClosureHandler (1.02s)1522=== CONT TestClientSharedPathCommittedMidPush1523--- PASS: TestReadProxyRangeRequest (0.58s)1524=== CONT TestLeadEndsOnShutdown15252026/10/01 07:31:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15262026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.65ms)15272026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)15282026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures15292026/10/01 07:31:57 OK 20241026095416_initial_model.sql (10.17ms)15302026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.27ms)15312026/10/01 07:31:57 INFO Received push request method=POST path=/api/pushes15322026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)15332026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)15342026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.51ms)15352026/10/01 07:31:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15362026/10/01 07:31:57 INFO Uploading r1gw4dzw01bvzcvw57n65gr6lx00zyi5-file1.txt (160B)1537=== RUN TestPush_RejectsBadRequests/root_not_in_objects1538=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1539=== RUN TestPush_RejectsBadRequests/no_roots1540=== PAUSE TestPush_RejectsBadRequests/no_roots1541=== RUN TestPush_RejectsBadRequests/no_objects1542=== PAUSE TestPush_RejectsBadRequests/no_objects1543=== RUN TestPush_RejectsBadRequests/bad_root1544=== PAUSE TestPush_RejectsBadRequests/bad_root1545=== CONT TestClientWithDependencies15462026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (17.71ms)15472026/10/01 07:31:57 OK 20260905000000_add_claims.sql (18.53ms)15482026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures15492026/10/01 07:31:57 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15502026/10/01 07:31:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15512026/10/01 07:31:57 WARN Failed to register uploaded object key=r1gw4dzw01bvzcvw57n65gr6lx00zyi5.ls error="server returned 404: 404 page not found\n"15522026/10/01 07:31:57 INFO Signed narinfos id=1 count=115532026/10/01 07:31:57 INFO Uploading 1 narinfos15542026/10/01 07:31:57 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YWZiNzU5NzItZWYzNC00NWUyLWIzOTItZjU4NDE2ZTIyN2M1LjEyMTI2NjU1LWM2YTItNDVjNi05ZDFkLWJjZTI0M2I4ZDliN3gxNzkwODM5OTE3NTEwNDk3MzY0 parts=1015552026/10/01 07:31:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15562026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (3.18ms)15572026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.5ms)15582026/10/01 07:31:57 INFO Received complete push request method=POST path=/api/pushes/1/complete15592026/10/01 07:31:57 WARN Failed to register uploaded object key=r1gw4dzw01bvzcvw57n65gr6lx00zyi5.narinfo error="server returned 404: 404 page not found\n"15602026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.49ms)15612026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (3.05ms)15622026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000015632026/10/01 07:31:57 INFO Completed upload id=115642026/10/01 07:31:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15652026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.27ms)15662026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000015672026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.96ms)15682026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures15692026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.37ms)15702026/10/01 07:31:57 OK 1_commit_pending_closure.sql (3.4ms)15712026-10-01 07:31:57.901 UTC [809] ERROR: relation "goose_db_version" does not exist at character 3615722026-10-01 07:31:57.901 UTC [809] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15732026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.83ms)15742026/10/01 07:31:57 OK 3_commit_push.sql (3.01ms)15752026/10/01 07:31:57 goose: up to current file version: 315762026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures15772026/10/01 07:31:57 OK 3_commit_push.sql (1.43ms)15782026/10/01 07:31:57 goose: up to current file version: 315792026/10/01 07:31:57 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15802026/10/01 07:31:57 WARN Found objects in DB but missing from S3, will re-upload count=115812026/10/01 07:31:57 INFO Upload complete. (80ms)1582=== NAME TestNARDeduplicationMetadataUploadBug1583 metadata_upload_test.go:54: Retrieved narinfo from S3:1584 StorePath: /build/TestNARDeduplicationMetadataUploadBug3094559875/001/store/r1gw4dzw01bvzcvw57n65gr6lx00zyi5-file1.txt1585 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1586 Compression: zstd1587 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1588 NarSize: 1601589 References: 1590 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1591--- PASS: TestService_verifyS3Integrity (1.08s)1592=== CONT TestLeadElectsOneAndHandsOver1593=== NAME TestNARDeduplicationMetadataUploadBug15942026-10-01 07:31:57.911 UTC [810] ERROR: relation "goose_db_version" does not exist at character 3615952026-10-01 07:31:57.911 UTC [810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1596 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1597 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1598 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15992026/10/01 07:31:57 OK 20241026095416_initial_model.sql (11.16ms)16002026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)16012026/10/01 07:31:57 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YWZiNzU5NzItZWYzNC00NWUyLWIzOTItZjU4NDE2ZTIyN2M1LmJkZjA3MGQxLWEzZTUtNDQyOC04YWE5LWEzYzE1MzI5Y2YxNXgxNzkwODM5OTE3NDUxNzYxMTgy parts=1216022026/10/01 07:31:57 OK 20251218171726_add_pins.sql (4.89ms)16032026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures16042026/10/01 07:31:57 OK 20241026095416_initial_model.sql (12.06ms)16052026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)1606--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.11s)1607=== CONT TestClientMultipleUploads16082026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)16092026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.53ms)16102026/10/01 07:31:57 OK 20251218171726_add_pins.sql (4.05ms)16112026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.78ms)16122026/10/01 07:31:57 INFO Received push request method=POST path=/api/pushes16132026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (2.3ms)16142026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000016152026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)16162026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.21ms)16172026/10/01 07:31:57 OK 2_object_stats_trigger.sql (1.5ms)16182026-10-01 07:31:57.945 UTC [834] ERROR: relation "goose_db_version" does not exist at character 3616192026-10-01 07:31:57.945 UTC [834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16202026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.2ms)16212026/10/01 07:31:57 OK 3_commit_push.sql (1.36ms)16222026/10/01 07:31:57 goose: up to current file version: 31623=== NAME TestNARDeduplicationMetadataUploadBug1624 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3094559875/001/store/pxn8hz1qnq2prwsg8mga0qd7ypndx0ld-file2.txt16252026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (12.02ms)16262026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (3.81ms)16272026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000016282026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.44ms)16292026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2ms)16302026/10/01 07:31:57 OK 3_commit_push.sql (1.84ms)16312026/10/01 07:31:57 goose: up to current file version: 316322026-10-01 07:31:57.970 UTC [852] ERROR: relation "goose_db_version" does not exist at character 3616332026-10-01 07:31:57.970 UTC [852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16342026-10-01 07:31:57.970 UTC [853] ERROR: relation "goose_db_version" does not exist at character 3616352026-10-01 07:31:57.970 UTC [853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16362026/10/01 07:31:57 OK 20241026095416_initial_model.sql (10.43ms)16372026/10/01 07:31:57 INFO Received uploads request method=POST path=/api/pending_closures16382026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)16392026/10/01 07:31:57 INFO Received complete push request method=POST path=/api/pushes/1/complete16402026/10/01 07:31:57 OK 20251218171726_add_pins.sql (3.04ms)16412026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)16422026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.13ms)16432026/10/01 07:31:57 OK 20260905000000_add_claims.sql (3.98ms)16442026/10/01 07:31:57 OK 20241026095416_initial_model.sql (9.2ms)16452026/10/01 07:31:57 INFO Received push request method=POST path=/api/pushes16462026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)16472026/10/01 07:31:57 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)16482026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.28ms)16492026/10/01 07:31:57 OK 20260923120000_add_pushes.sql (1.73ms)16502026/10/01 07:31:57 goose: successfully migrated database to version: 2026092312000016512026/10/01 07:31:57 INFO Received push request method=POST path=/api/pushes16522026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.96ms)16532026/10/01 07:31:57 OK 20251218171726_add_pins.sql (2.79ms)16542026/10/01 07:31:57 OK 1_commit_pending_closure.sql (2.08ms)16552026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (2.86ms)1656=== NAME TestPinProtectsFromGC1657 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC905840616/001/store/km9xln2v9d235vmmilyhvh8jkcdyzq9d-pinned-file.txt1658 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC905840616/001/store/93k7xdkilsh07x2dvr0snhmg2caarijr-unpinned-file.txt16592026/10/01 07:31:57 OK 2_object_stats_trigger.sql (2.1ms)16602026/10/01 07:31:57 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)16612026/10/01 07:31:57 OK 3_commit_push.sql (1.04ms)16622026/10/01 07:31:57 goose: up to current file version: 316632026/10/01 07:31:57 OK 20260905000000_add_claims.sql (2.4ms)16642026/10/01 07:31:57 OK 20260905000000_add_claims.sql (2.96ms)16652026-10-01 07:31:57.998 UTC [889] ERROR: relation "goose_db_version" does not exist at character 3616662026-10-01 07:31:57.998 UTC [889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16672026/10/01 07:31:57 OK 20260920000000_drop_claims.sql (2.91ms)16682026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.02ms)16692026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.91ms)16702026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000016712026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.04ms)16722026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000016732026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.3ms)16742026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.18ms)16752026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.3ms)16762026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.26ms)16772026/10/01 07:31:58 OK 3_commit_push.sql (875.6µs)16782026/10/01 07:31:58 goose: up to current file version: 316792026/10/01 07:31:58 OK 3_commit_push.sql (1.16ms)16802026/10/01 07:31:58 goose: up to current file version: 31681=== NAME TestOrphanedObjectsGC1682 orphaned_objects_gc_test.go:290: GC Test Summary:1683 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1684 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1685 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1686 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1687 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1688--- PASS: TestOrphanedObjectsGC (1.02s)1689=== CONT TestClientIntegration16902026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete16912026/10/01 07:31:58 OK 20241026095416_initial_model.sql (8.34ms)16922026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)16932026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.63ms)16942026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)16952026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes16962026-10-01 07:31:58.021 UTC [918] ERROR: relation "goose_db_version" does not exist at character 3616972026-10-01 07:31:58.021 UTC [918] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1698--- PASS: TestPush_CompleteCommitsEveryRoot (0.48s)1699=== CONT TestResolveDBConnectionString1700=== RUN TestResolveDBConnectionString/flag_wins17012026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.04ms)1702=== PAUSE TestResolveDBConnectionString/flag_wins1703=== RUN TestResolveDBConnectionString/file_when_flag_empty1704=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1705=== RUN TestResolveDBConnectionString/missing_file_is_an_error1706=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1707=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1708=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1709=== RUN TestResolveDBConnectionString/nothing_configured1710=== PAUSE TestResolveDBConnectionString/nothing_configured1711=== CONT TestClientErrorHandling1712=== RUN TestClientErrorHandling/InvalidStorePath1713=== PAUSE TestClientErrorHandling/InvalidStorePath1714=== RUN TestClientErrorHandling/InvalidAuthToken1715=== PAUSE TestClientErrorHandling/InvalidAuthToken1716=== RUN TestClientErrorHandling/ServerNotAvailable17172026/10/01 07:31:58 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1718=== PAUSE TestClientErrorHandling/ServerNotAvailable1719=== CONT TestClientCADerivations17202026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (1.83ms)17212026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.1ms)17222026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000017232026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17242026/10/01 07:31:58 WARN Failed to register uploaded object key=pxn8hz1qnq2prwsg8mga0qd7ypndx0ld.ls error="server returned 404: 404 page not found\n"17252026/10/01 07:31:58 INFO Signed narinfos id=2 count=117262026/10/01 07:31:58 INFO Uploading 1 narinfos17272026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.11ms)17282026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.68ms)17292026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes17302026/10/01 07:31:58 OK 3_commit_push.sql (1.57ms)17312026/10/01 07:31:58 goose: up to current file version: 317322026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/2/complete17332026/10/01 07:31:58 OK 20241026095416_initial_model.sql (8.37ms)17342026/10/01 07:31:58 WARN Failed to register uploaded object key=pxn8hz1qnq2prwsg8mga0qd7ypndx0ld.narinfo error="server returned 404: 404 page not found\n"17352026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (902.97µs)17362026/10/01 07:31:58 INFO Upload complete. (54ms)1737=== NAME TestNARDeduplicationMetadataUploadBug1738 metadata_upload_test.go:76: Retrieved narinfo from S3:1739 StorePath: /build/TestNARDeduplicationMetadataUploadBug3094559875/001/store/pxn8hz1qnq2prwsg8mga0qd7ypndx0ld-file2.txt1740 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1741 Compression: zstd1742 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1743 NarSize: 16017442026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.59ms)1745 References: 1746 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1747 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1748 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1749 {"version":1,"root":{"type":"regular","size":44}}17502026-10-01 07:31:58.043 UTC [939] ERROR: relation "goose_db_version" does not exist at character 3617512026-10-01 07:31:58.043 UTC [939] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17522026/10/01 07:31:58 INFO Aborted multipart uploads count=017532026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)17542026/10/01 07:31:58 INFO Aborted multipart uploads count=017552026/10/01 07:31:58 WARN Force mode enabled - objects will be deleted immediately without grace period17562026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.6ms)17572026/10/01 07:31:58 WARN Force mode enabled - objects will be deleted immediately without grace period1758--- PASS: TestNARDeduplicationMetadataUploadBug (0.97s)1759=== CONT TestClientFallsBackToClosures17602026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.63ms)17612026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (3.3ms)17622026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000017632026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.43ms)17642026/10/01 07:31:58 OK 20241026095416_initial_model.sql (8.39ms)17652026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.57ms)17662026/10/01 07:31:58 OK 3_commit_push.sql (880.73µs)17672026/10/01 07:31:58 goose: up to current file version: 317682026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)17692026/10/01 07:31:58 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=017702026/10/01 07:31:58 OK 20251218171726_add_pins.sql (4.72ms)17712026/10/01 07:31:58 INFO Received uploads request method=POST path=/api/pending_closures1772--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.44s)1773=== CONT TestClientPushesUseOnePush17742026/10/01 07:31:58 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=017752026/10/01 07:31:58 INFO Vacuumed table table=pending_closures17762026/10/01 07:31:58 INFO Vacuumed table table=pending_closures17772026/10/01 07:31:58 INFO Vacuumed table table=pending_objects17782026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads17792026/10/01 07:31:58 INFO Vacuumed table table=closures17802026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)17812026/10/01 07:31:58 INFO Vacuumed table table=pending_objects17822026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.34ms)17832026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes17842026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads1785--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.45s)1786=== CONT TestService_AuthMiddleware_OIDC17872026/10/01 07:31:58 INFO Vacuumed table table=objects1788--- PASS: TestGCSweepDeliversEachKeyOnce (0.53s)1789=== CONT TestService_ReadScope_PublicByDefault1790--- PASS: TestReadRedirectUsesPublicS3URL (0.46s)1791=== CONT TestService_RequireScope_OIDC17922026/10/01 07:31:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17932026/10/01 07:31:58 INFO Uploading km9xln2v9d235vmmilyhvh8jkcdyzq9d-pinned-file.txt (128B)17942026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (32.64ms)17952026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17962026/10/01 07:31:58 WARN Failed to register uploaded object key=km9xln2v9d235vmmilyhvh8jkcdyzq9d.ls error="server returned 404: 404 page not found\n"17972026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17982026/10/01 07:31:58 INFO Signed narinfos id=1 count=117992026/10/01 07:31:58 INFO Uploading 1 narinfos18002026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete18012026/10/01 07:31:58 WARN Failed to register uploaded object key=km9xln2v9d235vmmilyhvh8jkcdyzq9d.narinfo error="server returned 404: 404 page not found\n"18022026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (11.89ms)18032026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000018042026/10/01 07:31:58 INFO Vacuumed table table=closures18052026/10/01 07:31:58 OK 1_commit_pending_closure.sql (18.59ms)18062026/10/01 07:31:58 INFO Upload complete. (107ms)18072026/10/01 07:31:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42523/oidc18082026/10/01 07:31:58 INFO Vacuumed table table=objects18092026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/2/complete18102026/10/01 07:31:58 OK 2_object_stats_trigger.sql (16.15ms)18112026/10/01 07:31:58 OK 3_commit_push.sql (2.58ms)18122026/10/01 07:31:58 goose: up to current file version: 31813--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.69s)1814=== CONT TestCacheConfigHandler1815=== RUN TestCacheConfigHandler/full_config,_no_issuer1816=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1817=== RUN TestCacheConfigHandler/no_cache_url_configured1818=== PAUSE TestCacheConfigHandler/no_cache_url_configured1819=== RUN TestCacheConfigHandler/no_signing_keys1820=== PAUSE TestCacheConfigHandler/no_signing_keys1821=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1822=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1823=== CONT TestReadProxyRootRedirectsToIndexHTML18242026-10-01 07:31:58.161 UTC [967] ERROR: relation "goose_db_version" does not exist at character 3618252026-10-01 07:31:58.161 UTC [967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18262026-10-01 07:31:58.163 UTC [970] ERROR: relation "goose_db_version" does not exist at character 3618272026-10-01 07:31:58.163 UTC [970] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18282026/10/01 07:31:58 INFO Received uploads request method=POST path=/api/pending_closures18292026-10-01 07:31:58.172 UTC [974] ERROR: relation "goose_db_version" does not exist at character 3618302026-10-01 07:31:58.172 UTC [974] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18312026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.6ms)18322026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.29ms)18332026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)1834--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.69s)18352026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)1836=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18372026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.03ms)18382026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.78ms)18392026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)18402026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)18412026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.35ms)18422026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)18432026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.15ms)18442026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.91ms)18452026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2ms)18462026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.96ms)18472026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.7ms)18482026/10/01 07:31:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41817/oidc18492026/10/01 07:31:58 INFO Aborted multipart uploads count=018502026/10/01 07:31:58 WARN Force mode enabled - objects will be deleted immediately without grace period18512026/10/01 07:31:58 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=018522026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (11.5ms)18532026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000018542026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (13.55ms)18552026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000018562026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (13.66ms)18572026/10/01 07:31:58 INFO Vacuumed table table=pending_closures18582026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes18592026/10/01 07:31:58 OK 1_commit_pending_closure.sql (4.13ms)18602026/10/01 07:31:58 INFO Received uploads request method=POST path=/api/pending_closures18612026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.06ms)18622026/10/01 07:31:58 INFO Vacuumed table table=pending_objects18632026/10/01 07:31:58 INFO Received uploads request method=POST path=/api/pending_closures18642026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads18652026/10/01 07:31:58 INFO Vacuumed table table=closures18662026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.92ms)18672026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.94ms)18682026/10/01 07:31:58 OK 2_object_stats_trigger.sql (2.79ms)18692026/10/01 07:31:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18702026/10/01 07:31:58 INFO Uploading 93k7xdkilsh07x2dvr0snhmg2caarijr-unpinned-file.txt (128B)18712026/10/01 07:31:58 OK 3_commit_push.sql (2.34ms)18722026/10/01 07:31:58 goose: up to current file version: 318732026/10/01 07:31:58 INFO Vacuumed table table=objects18742026/10/01 07:31:58 OK 3_commit_push.sql (2.62ms)18752026/10/01 07:31:58 goose: up to current file version: 318762026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (4.26ms)18772026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18782026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18792026/10/01 07:31:58 WARN Failed to register uploaded object key=93k7xdkilsh07x2dvr0snhmg2caarijr.ls error="server returned 404: 404 page not found\n"18802026/10/01 07:31:58 INFO Signed narinfos id=2 count=118812026/10/01 07:31:58 INFO Uploading 1 narinfos18822026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/2/complete18832026/10/01 07:31:58 WARN Failed to register uploaded object key=93k7xdkilsh07x2dvr0snhmg2caarijr.narinfo error="server returned 404: 404 page not found\n"1884--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.50s)1885=== CONT TestReadRedirectKeepsNarinfoProxied18862026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (5.55ms)18872026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000018882026/10/01 07:31:58 INFO Upload complete. (46ms)18892026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.68ms)1890--- PASS: TestGCSweepSkipsPendingObjects (0.54s)1891=== CONT TestReadRedirectNar18922026/10/01 07:31:58 OK 2_object_stats_trigger.sql (2.97ms)18932026-10-01 07:31:58.228 UTC [1014] ERROR: relation "goose_db_version" does not exist at character 3618942026-10-01 07:31:58.228 UTC [1014] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18952026/10/01 07:31:58 OK 3_commit_push.sql (1.57ms)18962026/10/01 07:31:58 goose: up to current file version: 318972026/10/01 07:31:58 INFO Aborted multipart uploads count=018982026/10/01 07:31:58 WARN Force mode enabled - objects will be deleted immediately without grace period18992026/10/01 07:31:58 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=019002026/10/01 07:31:58 INFO Vacuumed table table=pending_closures19012026/10/01 07:31:58 INFO Vacuumed table table=pending_objects19022026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads19032026/10/01 07:31:58 INFO Vacuumed table table=closures19042026/10/01 07:31:58 INFO Vacuumed table table=objects19052026/10/01 07:31:58 OK 20241026095416_initial_model.sql (10.46ms)19062026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)19072026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.45ms)1908--- PASS: TestGCMetrics (0.47s)1909=== CONT TestService_ReadAuthMiddleware19102026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)1911--- PASS: TestCacheStatsHandler (0.50s)1912=== CONT TestReadProxyDisabled19132026/10/01 07:31:58 INFO Received create pin request method=POST path=/api/pins/myapp19142026/10/01 07:31:58 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC905840616/001/store/km9xln2v9d235vmmilyhvh8jkcdyzq9d-pinned-file.txt narinfo_key=km9xln2v9d235vmmilyhvh8jkcdyzq9d.narinfo19152026/10/01 07:31:58 OK 20260905000000_add_claims.sql (20.79ms)19162026/10/01 07:31:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures19172026/10/01 07:31:58 INFO Garbage collection started19182026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (3.08ms)19192026-10-01 07:31:58.283 UTC [1041] ERROR: relation "goose_db_version" does not exist at character 3619202026-10-01 07:31:58.283 UTC [1041] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19212026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.44ms)19222026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000019232026/10/01 07:31:58 INFO Aborted multipart uploads count=019242026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.33ms)19252026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.82ms)19262026-10-01 07:31:58.291 UTC [1044] ERROR: relation "goose_db_version" does not exist at character 3619272026-10-01 07:31:58.291 UTC [1044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19282026-10-01 07:31:58.291 UTC [1045] ERROR: relation "goose_db_version" does not exist at character 3619292026-10-01 07:31:58.291 UTC [1045] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19302026/10/01 07:31:58 OK 3_commit_push.sql (2.26ms)19312026/10/01 07:31:58 goose: up to current file version: 319322026/10/01 07:31:58 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=019332026/10/01 07:31:58 INFO Aborted multipart uploads count=019342026/10/01 07:31:58 INFO Vacuumed table table=pending_closures19352026/10/01 07:31:58 WARN Force mode enabled - objects will be deleted immediately without grace period19362026/10/01 07:31:58 OK 20241026095416_initial_model.sql (10.91ms)19372026-10-01 07:31:58.302 UTC [1048] ERROR: relation "goose_db_version" does not exist at character 3619382026-10-01 07:31:58.302 UTC [1048] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19392026/10/01 07:31:58 INFO Vacuumed table table=pending_objects19402026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)19412026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads19422026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.02ms)19432026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.26ms)19442026/10/01 07:31:58 OK 20241026095416_initial_model.sql (10.42ms)19452026/10/01 07:31:58 INFO Vacuumed table table=closures19462026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)19472026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)19482026/10/01 07:31:58 INFO lead: acquired remote=192.0.2.1:123419492026/10/01 07:31:58 INFO lead: released remote=192.0.2.1:12341950--- PASS: TestLeadEndsOnShutdown (0.46s)1951=== CONT TestReadProxyInvalidPath19522026/10/01 07:31:58 INFO Vacuumed table table=objects19532026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (4.18ms)19542026/10/01 07:31:58 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=019552026/10/01 07:31:58 OK 20251218171726_add_pins.sql (4.24ms)19562026/10/01 07:31:58 OK 20260905000000_add_claims.sql (4.14ms)19572026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.33ms)19582026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)19592026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.75ms)19602026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (3.39ms)19612026/10/01 07:31:58 INFO Aborted multipart uploads count=019622026/10/01 07:31:58 WARN Force mode enabled - objects will be deleted immediately without grace period19632026/10/01 07:31:58 INFO Vacuumed table table=pending_closures19642026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)19652026/10/01 07:31:58 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=019662026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.36ms)19672026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (4.66ms)19682026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.87ms)19692026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000019702026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.46ms)19712026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.37ms)19722026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.93ms)19732026/10/01 07:31:58 INFO Vacuumed table table=pending_objects19742026/10/01 07:31:58 INFO Vacuumed table table=pending_closures19752026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads19762026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.38ms)19772026-10-01 07:31:58.326 UTC [1052] ERROR: relation "goose_db_version" does not exist at character 3619782026-10-01 07:31:58.326 UTC [1052] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19792026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.74ms)19802026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000019812026/10/01 07:31:58 OK 2_object_stats_trigger.sql (2.4ms)19822026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.4ms)19832026/10/01 07:31:58 INFO Vacuumed table table=closures19842026/10/01 07:31:58 INFO Vacuumed table table=pending_objects19852026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)19862026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads19872026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.4ms)19882026/10/01 07:31:58 OK 3_commit_push.sql (2.3ms)19892026/10/01 07:31:58 goose: up to current file version: 319902026-10-01 07:31:58.335 UTC [1068] ERROR: relation "goose_db_version" does not exist at character 3619912026-10-01 07:31:58.335 UTC [1068] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19922026/10/01 07:31:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19932026/10/01 07:31:58 INFO Vacuumed table table=objects19942026/10/01 07:31:58 INFO Vacuumed table table=closures19952026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (10.91ms)19962026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000019972026/10/01 07:31:58 OK 2_object_stats_trigger.sql (12.57ms)19982026/10/01 07:31:58 OK 20260905000000_add_claims.sql (14.01ms)19992026/10/01 07:31:58 OK 1_commit_pending_closure.sql (4.89ms)20002026/10/01 07:31:58 INFO Vacuumed table table=objects20012026/10/01 07:31:58 OK 3_commit_push.sql (2.43ms)20022026/10/01 07:31:58 goose: up to current file version: 32003--- PASS: TestPushDedupSurvivesConcurrentGC (0.62s)2004=== CONT TestReadProxyConditionalGet20052026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.88ms)20062026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.89ms)20072026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.33ms)20082026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000020092026/10/01 07:31:58 OK 3_commit_push.sql (3.09ms)20102026/10/01 07:31:58 goose: up to current file version: 320112026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.81ms)20122026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.58ms)20132026-10-01 07:31:58.353 UTC [1072] ERROR: relation "goose_db_version" does not exist at character 3620142026-10-01 07:31:58.353 UTC [1072] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20152026/10/01 07:31:58 OK 2_object_stats_trigger.sql (2.54ms)20162026/10/01 07:31:58 OK 20241026095416_initial_model.sql (10.56ms)20172026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)20182026/10/01 07:31:58 OK 3_commit_push.sql (1.8ms)20192026/10/01 07:31:58 goose: up to current file version: 320202026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)20212026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.46ms)20222026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.77ms)20232026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)20242026/10/01 07:31:58 INFO lead: acquired remote=192.0.2.1:123420252026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)20262026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.59ms)20272026/10/01 07:31:58 OK 20260905000000_add_claims.sql (2.61ms)20282026/10/01 07:31:58 OK 20241026095416_initial_model.sql (8.27ms)20292026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.57ms)20302026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.95ms)20312026/10/01 07:31:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YWZiNzU5NzItZWYzNC00NWUyLWIzOTItZjU4NDE2ZTIyN2M1LjY1NWM1MThlLWJmNWYtNGExYi1iMGU5LTY0MTBkMWExOGJiMngxNzkwODM5OTE3ODcyMDExMzk2 parts=1220322026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)2033--- PASS: TestRedundantMultipartUpload (1.08s)20342026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (3.18ms)2035=== CONT TestReadProxy40420362026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000020372026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.84ms)20382026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000020392026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.93ms)20402026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.87ms)20412026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.56ms)20422026/10/01 07:31:58 OK 2_object_stats_trigger.sql (770.84µs)20432026-10-01 07:31:58.375 UTC [1107] ERROR: relation "goose_db_version" does not exist at character 3620442026-10-01 07:31:58.375 UTC [1107] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20452026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)20462026/10/01 07:31:58 OK 3_commit_push.sql (1.91ms)20472026/10/01 07:31:58 goose: up to current file version: 320482026/10/01 07:31:58 OK 2_object_stats_trigger.sql (2.15ms)20492026/10/01 07:31:58 OK 3_commit_push.sql (1.21ms)20502026/10/01 07:31:58 goose: up to current file version: 320512026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.05ms)20522026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.62ms)20532026-10-01 07:31:58.383 UTC [1111] ERROR: relation "goose_db_version" does not exist at character 3620542026-10-01 07:31:58.383 UTC [1111] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20552026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.28ms)20562026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000020572026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.04ms)20582026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.98ms)20592026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.27ms)20602026/10/01 07:31:58 OK 3_commit_push.sql (2.69ms)20612026/10/01 07:31:58 goose: up to current file version: 320622026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)20632026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.87ms)20642026/10/01 07:31:58 OK 20241026095416_initial_model.sql (9.58ms)20652026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)20662026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)20672026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.89ms)20682026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.17ms)20692026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)20702026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.94ms)20712026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (3.68ms)20722026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000020732026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.91ms)20742026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.13ms)20752026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.52ms)20762026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.23ms)20772026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.17ms)20782026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000020792026/10/01 07:31:58 OK 3_commit_push.sql (1.28ms)20802026/10/01 07:31:58 goose: up to current file version: 320812026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2ms)20822026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.61ms)20832026/10/01 07:31:58 OK 3_commit_push.sql (1.08ms)20842026/10/01 07:31:58 goose: up to current file version: 320852026-10-01 07:31:58.423 UTC [1165] ERROR: relation "goose_db_version" does not exist at character 3620862026-10-01 07:31:58.423 UTC [1165] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2087=== NAME TestClientMultipleUploads2088 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads6030546/001/store/67czy9dzn9kac37vllq5kfm3wglzzqvf-test-file-0.txt2089=== NAME TestClientWithDependencies2090 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies487955230/001/store/1hf0d4daj2iiv5pzhldqzjzk2v6azbpj-test-script20912026/10/01 07:31:58 OK 20241026095416_initial_model.sql (14.77ms)20922026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)20932026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes20942026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.69ms)20952026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (2.91ms)20962026/10/01 07:31:58 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20972026/10/01 07:31:58 OK 20260905000000_add_claims.sql (2.6ms)20982026/10/01 07:31:58 INFO Uploading pqw25gz8dd03nhkc72gcjzfkcm38bldp-shared-dep (136B)20992026-10-01 07:31:58.453 UTC [1204] ERROR: relation "goose_db_version" does not exist at character 3621002026-10-01 07:31:58.453 UTC [1204] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21012026/10/01 07:31:58 INFO Uploading rh2867r2ix09rp6pcq342wdb1snm4i53-top (224B)21022026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.03ms)21032026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.19ms)21042026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000021052026/10/01 07:31:58 WARN Failed to register uploaded object key=pqw25gz8dd03nhkc72gcjzfkcm38bldp.ls error="server returned 404: 404 page not found\n"21062026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.58ms)21072026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"2108=== NAME TestClientMultipleUploads21092026/10/01 07:31:58 OK 2_object_stats_trigger.sql (758.66µs)2110 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads6030546/001/store/k8bbf78rzp7flkb48d622qll28c9laq1-test-file-1.txt21112026/10/01 07:31:58 WARN Failed to register uploaded object key=rh2867r2ix09rp6pcq342wdb1snm4i53.ls error="server returned 404: 404 page not found\n"21122026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/1nqrk0apng50k5d71qqn8gvhaviql1a65fzcc5gfqwxk4rzgarfc.nar.zst error="server returned 404: 404 page not found\n"21132026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21142026/10/01 07:31:58 INFO Signed narinfos id=1 count=221152026/10/01 07:31:58 OK 3_commit_push.sql (704.4µs)21162026/10/01 07:31:58 goose: up to current file version: 321172026/10/01 07:31:58 INFO Uploading 2 narinfos2118=== NAME TestClientWithDependencies2119 client_integration_test.go:615: Found 1 dependencies (including self)21202026/10/01 07:31:58 WARN Failed to register uploaded object key=pqw25gz8dd03nhkc72gcjzfkcm38bldp.narinfo error="server returned 404: 404 page not found\n"21212026-10-01 07:31:58.465 UTC [1238] ERROR: relation "goose_db_version" does not exist at character 3621222026-10-01 07:31:58.465 UTC [1238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21232026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete21242026/10/01 07:31:58 WARN Failed to register uploaded object key=rh2867r2ix09rp6pcq342wdb1snm4i53.narinfo error="server returned 404: 404 page not found\n"21252026/10/01 07:31:58 OK 20241026095416_initial_model.sql (7.1ms)21262026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)21272026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.32ms)21282026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (2.76ms)21292026/10/01 07:31:58 INFO Upload complete. (69ms)21302026/10/01 07:31:58 OK 20260905000000_add_claims.sql (2.96ms)2131=== NAME TestClientSharedPathCommittedMidPush2132 client_integration_test.go:680: Retrieved narinfo from S3:2133 StorePath: /build/TestClientSharedPathCommittedMidPush3521128557/001/store/pqw25gz8dd03nhkc72gcjzfkcm38bldp-shared-dep2134 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2135 Compression: zstd2136 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822137 NarSize: 1362138 References: 2139 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21402026/10/01 07:31:58 OK 20241026095416_initial_model.sql (7.49ms)21412026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.42ms)2142=== NAME TestClientIntegration2143 client_integration_test.go:286: Created store path: /build/TestClientIntegration2054929760/002/store/l6b75mnhx5qgfxf6nq9rs6d19wqnjnjn-test-file.txt21442026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (963.77µs)2145=== NAME TestClientSharedPathCommittedMidPush2146 client_integration_test.go:680: Retrieved narinfo from S3:2147 StorePath: /build/TestClientSharedPathCommittedMidPush3521128557/001/store/rh2867r2ix09rp6pcq342wdb1snm4i53-top2148 URL: nar/1nqrk0apng50k5d71qqn8gvhaviql1a65fzcc5gfqwxk4rzgarfc.nar.zst2149 Compression: zstd2150 NarHash: sha256:1nqrk0apng50k5d71qqn8gvhaviql1a65fzcc5gfqwxk4rzgarfc2151 NarSize: 2242152 References: /build/TestClientSharedPathCommittedMidPush3521128557/001/store/pqw25gz8dd03nhkc72gcjzfkcm38bldp-shared-dep2153 CA: text:sha256:0fcgpacyncrbdym42r0x84ffhcsm6nggdjz0pcaw7jk9fzmjf1f721542026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.3ms)21552026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000021562026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.17ms)21572026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.81ms)21582026/10/01 07:31:58 OK 2_object_stats_trigger.sql (692.71µs)21592026/10/01 07:31:58 OK 3_commit_push.sql (744.59µs)21602026/10/01 07:31:58 goose: up to current file version: 321612026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)2162--- PASS: TestClientSharedPathCommittedMidPush (0.64s)2163=== CONT TestService_AuthMiddleware_MTLSProxyHeader21642026/10/01 07:31:58 OK 20260905000000_add_claims.sql (2.58ms)21652026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (1.38ms)21662026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.04ms)21672026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000021682026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.35ms)21692026/10/01 07:31:58 OK 2_object_stats_trigger.sql (784.8µs)21702026/10/01 07:31:58 OK 3_commit_push.sql (825.79µs)21712026/10/01 07:31:58 goose: up to current file version: 32172--- PASS: TestService_ReadScope_PublicByDefault (0.41s)2173=== CONT TestReadProxyHead2174=== NAME TestClientMultipleUploads2175 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads6030546/001/store/l93apkmq2s8wfqkmq5nh4g8lf52s6b4r-test-file-2.txt2176=== NAME TestClientCADerivations2177 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1525548121/001/store/2mci3p4wjjydqak8lsfb5g27b77lcj2v-ca-test21782026/10/01 07:31:58 INFO lead: released remote=192.0.2.1:12342179--- PASS: TestGCBugBareHashReferences (0.69s)2180=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21812026/10/01 07:31:58 INFO Received uploads request method=POST path=/2182=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21832026/10/01 07:31:58 INFO Received request for more parts method=POST path=/2184=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21852026/10/01 07:31:58 INFO Received complete multipart upload request method=POST path=/2186=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21872026/10/01 07:31:58 INFO Received uploads request method=POST path=/2188--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2189 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2190 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2191 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2192 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2193=== CONT TestProxyWriteTimeout/narinfo2194=== CONT TestProxyWriteTimeout/unknown_size2195=== CONT TestProxyWriteTimeout/10_GiB_nar2196=== CONT TestProxyWriteTimeout/1_GiB_nar2197--- PASS: TestProxyWriteTimeout (0.16s)2198 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2199 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2200 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2201 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2202=== CONT TestParseSingleRange/none2203=== CONT TestParseSingleRange/start_far_past_EOF2204=== CONT TestParseSingleRange/start_past_EOF2205=== CONT TestParseSingleRange/single_byte2206=== CONT TestParseSingleRange/suffix_exceeds_size2207=== CONT TestParseSingleRange/suffix2208=== CONT TestParseSingleRange/end_clamped_to_size2209=== CONT TestParseSingleRange/malformed_no_dash2210=== CONT TestParseSingleRange/multi-range_ignored2211=== CONT TestParseSingleRange/unknown_unit2212=== CONT TestParseSingleRange/closed2213=== CONT TestParseSingleRange/malformed_both_empty2214=== CONT TestParseSingleRange/open-ended2215=== CONT TestParseSingleRange/malformed_end_before_start2216--- PASS: TestParseSingleRange (0.01s)2217 --- PASS: TestParseSingleRange/none (0.00s)2218 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2219 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2220 --- PASS: TestParseSingleRange/single_byte (0.00s)2221 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2222 --- PASS: TestParseSingleRange/suffix (0.00s)2223 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2224 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2225 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2226 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2227 --- PASS: TestParseSingleRange/closed (0.00s)2228 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2229 --- PASS: TestParseSingleRange/open-ended (0.00s)2230 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2231=== CONT TestIsValidCachePath/narinfo2232=== CONT TestIsValidCachePath/index.html2233=== CONT TestIsValidCachePath/nix-cache-info2234=== CONT TestIsValidCachePath/realisation2235=== CONT TestIsValidCachePath/log2236=== CONT TestIsValidCachePath/ls2237=== CONT TestIsValidCachePath/nar_uncompressed2238=== CONT TestIsValidCachePath/nar_bz22239=== CONT TestIsValidCachePath/nar_xz2240=== CONT TestIsValidCachePath/nar_zst2241=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2242=== CONT TestIsValidCachePath/empty2243=== CONT TestIsValidCachePath/short_hash2244=== CONT TestIsValidCachePath/wrong_extension2245=== CONT TestIsValidCachePath/leading_slash2246=== CONT TestIsValidCachePath/invalid_char_u2247=== CONT TestIsValidCachePath/random_path2248=== CONT TestIsValidCachePath/invalid_char_e2249=== CONT TestIsValidCachePath/traversal_in_middle2250=== CONT TestIsValidCachePath/traversal_parent2251--- PASS: TestIsValidCachePath (0.01s)2252 --- PASS: TestIsValidCachePath/narinfo (0.00s)2253 --- PASS: TestIsValidCachePath/index.html (0.00s)2254 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2255 --- PASS: TestIsValidCachePath/realisation (0.00s)2256 --- PASS: TestIsValidCachePath/log (0.00s)2257 --- PASS: TestIsValidCachePath/ls (0.00s)2258 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2259 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2260 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2261 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2262 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2263 --- PASS: TestIsValidCachePath/empty (0.00s)2264 --- PASS: TestIsValidCachePath/short_hash (0.00s)2265 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2266 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2267 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2268 --- PASS: TestIsValidCachePath/random_path (0.00s)2269 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2270 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2271 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2272=== CONT TestIsValidUploadKey/narinfo2273=== CONT TestIsValidUploadKey/unknown_type2274=== CONT TestIsValidUploadKey/empty_key2275=== CONT TestIsValidUploadKey/absolute2276=== CONT TestIsValidUploadKey/traversal_nar2277=== CONT TestIsValidUploadKey/traversal2278=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2279=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2280=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2281=== CONT TestIsValidUploadKey/index.html2282=== CONT TestIsValidUploadKey/nix-cache-info2283=== CONT TestIsValidUploadKey/realisation_plus_in_output2284=== CONT TestIsValidUploadKey/realisation2285=== CONT TestIsValidUploadKey/build_log_equals2286=== CONT TestIsValidUploadKey/build_log_question_mark2287=== CONT TestIsValidUploadKey/build_log_plus_in_name2288=== CONT TestIsValidUploadKey/build_log_home-manager_file2289=== CONT TestIsValidUploadKey/nar_xz2290=== CONT TestIsValidUploadKey/nar_zst2291=== CONT TestIsValidUploadKey/build_log2292=== CONT TestIsValidUploadKey/listing2293=== CONT TestIsValidUploadKey/nar_plain2294--- PASS: TestIsValidUploadKey (0.17s)2295 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2296 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2297 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2298 --- PASS: TestIsValidUploadKey/absolute (0.00s)2299 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2300 --- PASS: TestIsValidUploadKey/traversal (0.00s)2301 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2302 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2303 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2304 --- PASS: TestIsValidUploadKey/index.html (0.00s)2305 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2306 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2307 --- PASS: TestIsValidUploadKey/realisation (0.00s)2308 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2309 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2310 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2311 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2312 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2313 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2314 --- PASS: TestIsValidUploadKey/build_log (0.00s)2315 --- PASS: TestIsValidUploadKey/listing (0.00s)2316 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2317=== CONT TestServerTLSConfig/no_client_CA2318=== CONT TestServerTLSConfig/not_a_PEM_file2319=== CONT TestServerTLSConfig/missing_CA_file2320--- PASS: TestServerTLSConfig (0.00s)2321 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2322 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2323 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2324=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23252026/10/01 07:31:58 INFO Received uploads request method=POST path=/2326=== NAME TestClientCADerivations2327 client_ca_test.go:139: Found 1 dependencies (including self)23282026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes2329--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.39s)2330=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23312026/10/01 07:31:58 INFO Received request for more parts method=POST path=/23322026/10/01 07:31:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23332026/10/01 07:31:58 INFO Uploading 1hf0d4daj2iiv5pzhldqzjzk2v6azbpj-test-script (136B)23342026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes23352026/10/01 07:31:58 WARN Failed to register uploaded object key=1hf0d4daj2iiv5pzhldqzjzk2v6azbpj.ls error="server returned 404: 404 page not found\n"23362026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"23372026/10/01 07:31:58 WARN Failed to register uploaded object key=log/2v44p6rmfvj6ag2zwj9r7g534208iply-test-script.drv error="server returned 404: 404 page not found\n"23382026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23392026/10/01 07:31:58 INFO Signed narinfos id=1 count=123402026/10/01 07:31:58 INFO Uploading 1 narinfos23412026/10/01 07:31:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23422026/10/01 07:31:58 INFO lead: acquired remote=192.0.2.1:123423432026/10/01 07:31:58 INFO Uploading l6b75mnhx5qgfxf6nq9rs6d19wqnjnjn-test-file.txt (152B)23442026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete23452026/10/01 07:31:58 WARN Failed to register uploaded object key=1hf0d4daj2iiv5pzhldqzjzk2v6azbpj.narinfo error="server returned 404: 404 page not found\n"23462026/10/01 07:31:58 WARN Failed to register uploaded object key=l6b75mnhx5qgfxf6nq9rs6d19wqnjnjn.ls error="server returned 404: 404 page not found\n"23472026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23482026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"23492026/10/01 07:31:58 INFO Signed narinfos id=1 count=123502026/10/01 07:31:58 INFO Uploading 1 narinfos23512026/10/01 07:31:58 INFO lead: released remote=192.0.2.1:12342352--- PASS: TestLeadElectsOneAndHandsOver (0.66s)2353=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23542026/10/01 07:31:58 INFO Received complete multipart upload request method=POST path=/23552026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete23562026/10/01 07:31:58 WARN Failed to register uploaded object key=l6b75mnhx5qgfxf6nq9rs6d19wqnjnjn.narinfo error="server returned 404: 404 page not found\n"23572026-10-01 07:31:58.574 UTC [1482] ERROR: relation "goose_db_version" does not exist at character 3623582026-10-01 07:31:58.574 UTC [1482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23592026/10/01 07:31:58 INFO Upload complete. (75ms)23602026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes2361=== NAME TestClientWithDependencies2362 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies487955230/001/store) requires matching store prefix2363=== CONT TestPush_RejectsBadRequests/root_not_in_objects23642026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes2365=== CONT TestPush_RejectsBadRequests/no_objects23662026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes2367=== CONT TestPush_RejectsBadRequests/bad_root23682026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes2369=== CONT TestPush_RejectsBadRequests/no_roots23702026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes2371=== CONT TestResolveDBConnectionString/flag_wins2372=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2373=== CONT TestResolveDBConnectionString/nothing_configured2374=== CONT TestResolveDBConnectionString/missing_file_is_an_error2375--- PASS: TestPush_RejectsBadRequests (0.57s)2376 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2377 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2378 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2379 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2380=== CONT TestResolveDBConnectionString/file_when_flag_empty2381=== CONT TestClientErrorHandling/InvalidStorePath2382--- PASS: TestResolveDBConnectionString (0.00s)2383 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2384 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2385 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2386 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2387 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2388--- PASS: TestClientWithDependencies (0.71s)2389=== CONT TestClientErrorHandling/ServerNotAvailable23902026/10/01 07:31:58 INFO Upload complete. (83ms)2391=== RUN TestService_RequireScope_OIDC/builder_may_write2392=== PAUSE TestService_RequireScope_OIDC/builder_may_write2393=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2394=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2395=== RUN TestService_RequireScope_OIDC/ops_may_admin2396=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2397=== RUN TestService_RequireScope_OIDC/ops_may_not_write2398=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2399=== RUN TestService_RequireScope_OIDC/reader_may_not_write2400=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2401=== RUN TestService_RequireScope_OIDC/static_token_may_admin2402=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2403=== RUN TestService_RequireScope_OIDC/static_token_may_write2404=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2405=== RUN TestService_RequireScope_OIDC/reader_may_read2406=== PAUSE TestService_RequireScope_OIDC/reader_may_read2407=== RUN TestService_RequireScope_OIDC/writer_implies_read2408=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2409=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2410=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2411=== CONT TestClientErrorHandling/InvalidAuthToken24122026-10-01 07:31:58.603 UTC [1530] ERROR: relation "goose_db_version" does not exist at character 3624132026-10-01 07:31:58.603 UTC [1530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24142026/10/01 07:31:58 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)24152026/10/01 07:31:58 INFO Uploading l93apkmq2s8wfqkmq5nh4g8lf52s6b4r-test-file-2.txt (160B)24162026/10/01 07:31:58 INFO Uploading k8bbf78rzp7flkb48d622qll28c9laq1-test-file-1.txt (160B)24172026/10/01 07:31:58 INFO Uploading 67czy9dzn9kac37vllq5kfm3wglzzqvf-test-file-0.txt (160B)24182026/10/01 07:31:58 OK 20241026095416_initial_model.sql (16.16ms)24192026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)24202026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"24212026/10/01 07:31:58 WARN Failed to register uploaded object key=l93apkmq2s8wfqkmq5nh4g8lf52s6b4r.ls error="server returned 404: 404 page not found\n"24222026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"24232026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"24242026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.99ms)24252026/10/01 07:31:58 WARN Failed to register uploaded object key=k8bbf78rzp7flkb48d622qll28c9laq1.ls error="server returned 404: 404 page not found\n"24262026/10/01 07:31:58 WARN Failed to register uploaded object key=67czy9dzn9kac37vllq5kfm3wglzzqvf.ls error="server returned 404: 404 page not found\n"24272026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24282026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (2.49ms)24292026/10/01 07:31:58 INFO Signed narinfos id=1 count=324302026/10/01 07:31:58 INFO Uploading 3 narinfos24312026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.28ms)24322026/10/01 07:31:58 OK 20241026095416_initial_model.sql (7.86ms)24332026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (1.9ms)24342026/10/01 07:31:58 WARN Failed to register uploaded object key=67czy9dzn9kac37vllq5kfm3wglzzqvf.narinfo error="server returned 404: 404 page not found\n"24352026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete24362026/10/01 07:31:58 WARN Failed to register uploaded object key=l93apkmq2s8wfqkmq5nh4g8lf52s6b4r.narinfo error="server returned 404: 404 page not found\n"24372026/10/01 07:31:58 WARN Failed to register uploaded object key=k8bbf78rzp7flkb48d622qll28c9laq1.narinfo error="server returned 404: 404 page not found\n"24382026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)24392026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (3.02ms)24402026/10/01 07:31:58 goose: successfully migrated database to version: 202609231200002441=== CONT TestCacheConfigHandler/full_config,_no_issuer2442=== CONT TestCacheConfigHandler/no_signing_keys2443=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2444=== CONT TestCacheConfigHandler/no_cache_url_configured2445--- PASS: TestCacheConfigHandler (0.00s)2446 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2447 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2448 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2449 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)24502026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.41ms)2451=== CONT TestService_RequireScope_OIDC/builder_may_write2452=== CONT TestService_RequireScope_OIDC/static_token_may_admin2453=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2454=== CONT TestService_RequireScope_OIDC/writer_implies_read2455=== CONT TestService_RequireScope_OIDC/reader_may_read24562026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.11ms)2457=== CONT TestService_RequireScope_OIDC/static_token_may_write2458=== CONT TestService_RequireScope_OIDC/ops_may_not_write24592026/10/01 07:31:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"2460=== CONT TestService_RequireScope_OIDC/ops_may_admin24612026/10/01 07:31:58 WARN mTLS auth: bound subjects configured but subject DN unavailable2462=== CONT TestService_RequireScope_OIDC/reader_may_not_write24632026/10/01 07:31:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2464=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2465--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.44s)24662026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.04ms)2467--- PASS: TestService_RequireScope_OIDC (0.50s)2468 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2469 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2470 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2471 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2472 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2473 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2474 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2475 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2476 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2477 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)24782026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)24792026/10/01 07:31:58 OK 3_commit_push.sql (2.11ms)24802026/10/01 07:31:58 goose: up to current file version: 324812026/10/01 07:31:58 INFO Upload complete. (89ms)2482=== NAME TestClientMultipleUploads2483 client_integration_test.go:369: Uploaded 3 paths in 125.193775ms24842026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.59ms)24852026/10/01 07:31:58 INFO All 1 paths already cached2486=== NAME TestClientIntegration2487 client_integration_test.go:312: Retrieved narinfo from S3:2488 StorePath: /build/TestClientIntegration2054929760/002/store/l6b75mnhx5qgfxf6nq9rs6d19wqnjnjn-test-file.txt2489 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2490 Compression: zstd2491 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12492 NarSize: 1522493 References: 2494 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk124952026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.34ms)2496 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2497 client_integration_test.go:313: Decompressed .ls content (64 bytes):2498 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2499 client_integration_test.go:316: Testing garbage collection...25002026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (2.75ms)25012026/10/01 07:31:58 goose: successfully migrated database to version: 202609231200002502--- PASS: TestClientMultipleUploads (0.71s)25032026/10/01 07:31:58 OK 1_commit_pending_closure.sql (2.2ms)25042026/10/01 07:31:58 OK 2_object_stats_trigger.sql (1.38ms)25052026/10/01 07:31:58 OK 3_commit_push.sql (1.24ms)25062026/10/01 07:31:58 goose: up to current file version: 32507=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2508=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2509=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2510=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2511=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2512=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2513=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2514=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2515=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2516=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2517=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured25182026/10/01 07:31:58 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2519=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected25202026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes25212026/10/01 07:31:58 WARN Authentication failed token_preview=eyJhbGciOi...cowE4yapgg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2522--- PASS: TestService_AuthMiddleware_OIDC (0.55s)2523 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2524 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2525 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2526 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)25272026/10/01 07:31:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25282026/10/01 07:31:58 INFO Uploading 2mci3p4wjjydqak8lsfb5g27b77lcj2v-ca-test (144B)25292026/10/01 07:31:58 WARN Failed to register uploaded object key=2mci3p4wjjydqak8lsfb5g27b77lcj2v.ls error="server returned 404: 404 page not found\n"25302026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25312026/10/01 07:31:58 WARN Failed to register uploaded object key=log/5x252lxc9pri6dzmy7lirhg3ppcklygk-ca-test.drv error="server returned 404: 404 page not found\n"25322026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25332026/10/01 07:31:58 INFO Signed narinfos id=1 count=125342026/10/01 07:31:58 INFO Uploading 1 narinfos25352026/10/01 07:31:58 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/present2536--- PASS: TestReadRedirectKeepsNarinfoProxied (0.45s)25372026/10/01 07:31:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures25382026/10/01 07:31:58 INFO Garbage collection started25392026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete25402026/10/01 07:31:58 WARN Failed to register uploaded object key=2mci3p4wjjydqak8lsfb5g27b77lcj2v.narinfo error="server returned 404: 404 page not found\n"25412026-10-01 07:31:58.679 UTC [1692] ERROR: relation "goose_db_version" does not exist at character 3625422026-10-01 07:31:58.679 UTC [1692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25432026/10/01 07:31:58 INFO Upload complete. (103ms)25442026/10/01 07:31:58 INFO Aborted multipart uploads count=02545=== NAME TestClientCADerivations2546 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1525548121/001/store/2mci3p4wjjydqak8lsfb5g27b77lcj2v-ca-test2547 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2548 Compression: zstd2549 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2550 NarSize: 1442551 References: 2552 Deriver: /build/TestClientCADerivations1525548121/001/store/5x252lxc9pri6dzmy7lirhg3ppcklygk-ca-test.drv2553 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2554 client_ca_test.go:185: Checking for realisation files in S3...25552026-10-01 07:31:58.683 UTC [1694] ERROR: relation "goose_db_version" does not exist at character 3625562026-10-01 07:31:58.683 UTC [1694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25572026/10/01 07:31:58 WARN Force mode enabled - objects will be deleted immediately without grace period2558 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2559 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache25602026/10/01 07:31:58 INFO Received uploads request method=POST path=/api/pending_closures25612026/10/01 07:31:58 OK 20241026095416_initial_model.sql (7.21ms)2562--- PASS: TestReadRedirectNar (0.46s)25632026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)25642026/10/01 07:31:58 OK 20241026095416_initial_model.sql (7.07ms)25652026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.37ms)25662026/10/01 07:31:58 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=025672026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)25682026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (2.75ms)25692026/10/01 07:31:58 INFO Received uploads request method=POST path=/api/pending_closures25702026/10/01 07:31:58 OK 20251218171726_add_pins.sql (1.99ms)25712026/10/01 07:31:58 INFO Vacuumed table table=pending_closures2572--- PASS: TestService_ReadAuthMiddleware (0.45s)25732026/10/01 07:31:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)25742026/10/01 07:31:58 INFO Uploading hgynaq1r6sb66wmgp7rvi5lxvjadx6r6-a (216B)25752026/10/01 07:31:58 INFO Uploading cgi1cjpqilfkd5yq9p6fd9bj9q2xwwx9-shared-dep (136B)25762026/10/01 07:31:58 OK 20260905000000_add_claims.sql (2.57ms)25772026/10/01 07:31:58 INFO Vacuumed table table=pending_objects25782026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (1.54ms)25792026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)25802026/10/01 07:31:58 INFO Vacuumed table table=multipart_uploads25812026/10/01 07:31:58 WARN Failed to register uploaded object key=hgynaq1r6sb66wmgp7rvi5lxvjadx6r6.ls error="server returned 404: 404 page not found\n"25822026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/1zx0bvay7qfykw9gipivk5kcniszaz2yqmrh95kn450wq5l76pb5.nar.zst error="server returned 404: 404 page not found\n"25832026/10/01 07:31:58 WARN Failed to register uploaded object key=zqgzlplpa90kcih4jixmr2zlj57af9qp.ls error="server returned 404: 404 page not found\n"25842026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"25852026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.81ms)25862026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000025872026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25882026/10/01 07:31:58 WARN Failed to register uploaded object key=cgi1cjpqilfkd5yq9p6fd9bj9q2xwwx9.ls error="server returned 404: 404 page not found\n"25892026/10/01 07:31:58 INFO Vacuumed table table=closures25902026/10/01 07:31:58 INFO Signed narinfos id=1 count=225912026/10/01 07:31:58 OK 20260905000000_add_claims.sql (2.55ms)25922026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign25932026/10/01 07:31:58 INFO Signed narinfos id=2 count=225942026/10/01 07:31:58 INFO Uploading 4 narinfos25952026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.62ms)25962026/10/01 07:31:58 INFO Vacuumed table table=objects25972026/10/01 07:31:58 OK 2_object_stats_trigger.sql (682.32µs)25982026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (1.77ms)25992026/10/01 07:31:58 OK 3_commit_push.sql (555.51µs)26002026/10/01 07:31:58 goose: up to current file version: 326012026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.18ms)26022026/10/01 07:31:58 goose: successfully migrated database to version: 2026092312000026032026/10/01 07:31:58 WARN Failed to register uploaded object key=cgi1cjpqilfkd5yq9p6fd9bj9q2xwwx9.narinfo error="server returned 404: 404 page not found\n"26042026/10/01 07:31:58 WARN Failed to register uploaded object key=hgynaq1r6sb66wmgp7rvi5lxvjadx6r6.narinfo error="server returned 404: 404 page not found\n"26052026/10/01 07:31:58 WARN Failed to register uploaded object key=zqgzlplpa90kcih4jixmr2zlj57af9qp.narinfo error="server returned 404: 404 page not found\n"26062026/10/01 07:31:58 INFO Received push request method=POST path=/api/pushes26072026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.69ms)26082026/10/01 07:31:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete26092026/10/01 07:31:58 WARN Failed to register uploaded object key=cgi1cjpqilfkd5yq9p6fd9bj9q2xwwx9.narinfo error="server returned 404: 404 page not found\n"26102026/10/01 07:31:58 OK 2_object_stats_trigger.sql (724.17µs)26112026/10/01 07:31:58 OK 3_commit_push.sql (736.9µs)26122026/10/01 07:31:58 goose: up to current file version: 326132026/10/01 07:31:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)26142026/10/01 07:31:58 INFO Uploading ygzlz6drzibvssw34y7pkcq06a03k9ky-a (216B)26152026/10/01 07:31:58 INFO Uploading wlacx2n2n0pg59wjs6zlmas38ikywc0z-shared-dep (136B)2616--- PASS: TestReadProxyDisabled (0.46s)26172026/10/01 07:31:58 INFO Completed upload id=126182026/10/01 07:31:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete26192026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"26202026/10/01 07:31:58 WARN Failed to register uploaded object key=ygzlz6drzibvssw34y7pkcq06a03k9ky.ls error="server returned 404: 404 page not found\n"26212026/10/01 07:31:58 WARN Failed to register uploaded object key=nar/0c2znbk7xjv0sdmx9ibqs8j7iqgp48s2nmjp1xfqdi8g3wp4garn.nar.zst error="server returned 404: 404 page not found\n"26222026/10/01 07:31:58 WARN Failed to register uploaded object key=wlacx2n2n0pg59wjs6zlmas38ikywc0z.ls error="server returned 404: 404 page not found\n"26232026/10/01 07:31:58 INFO Completed upload id=226242026/10/01 07:31:58 INFO Upload complete. (71ms)26252026/10/01 07:31:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26262026/10/01 07:31:58 WARN Failed to register uploaded object key=5n9cbcyw9a6zjyms8sd2a3b8rxqpp5gk.ls error="server returned 404: 404 page not found\n"26272026/10/01 07:31:58 INFO Signed narinfos id=1 count=326282026/10/01 07:31:58 INFO Uploading 3 narinfos2629=== NAME TestClientFallsBackToClosures2630 client_pushes_test.go:112: Retrieved narinfo from S3:2631 StorePath: /build/TestClientFallsBackToClosures4159360235/001/store/cgi1cjpqilfkd5yq9p6fd9bj9q2xwwx9-shared-dep2632 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2633 Compression: zstd2634 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822635 NarSize: 1362636 References: 2637 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n26382026/10/01 07:31:58 WARN Failed to register uploaded object key=wlacx2n2n0pg59wjs6zlmas38ikywc0z.narinfo error="server returned 404: 404 page not found\n"26392026/10/01 07:31:58 WARN Failed to register uploaded object key=5n9cbcyw9a6zjyms8sd2a3b8rxqpp5gk.narinfo error="server returned 404: 404 page not found\n"2640 client_pushes_test.go:112: Retrieved narinfo from S3:2641 StorePath: /build/TestClientFallsBackToClosures4159360235/001/store/hgynaq1r6sb66wmgp7rvi5lxvjadx6r6-a2642 URL: nar/1zx0bvay7qfykw9gipivk5kcniszaz2yqmrh95kn450wq5l76pb5.nar.zst2643 Compression: zstd2644 NarHash: sha256:1zx0bvay7qfykw9gipivk5kcniszaz2yqmrh95kn450wq5l76pb52645 NarSize: 2162646 References: /build/TestClientFallsBackToClosures4159360235/001/store/cgi1cjpqilfkd5yq9p6fd9bj9q2xwwx9-shared-dep2647 CA: text:sha256:1vbynbs7vbp3vi63g70mmhdwywi9wlrndnyv1aw60xqf43s7rajh26482026/10/01 07:31:58 INFO Received complete push request method=POST path=/api/pushes/1/complete26492026/10/01 07:31:58 WARN Failed to register uploaded object key=ygzlz6drzibvssw34y7pkcq06a03k9ky.narinfo error="server returned 404: 404 page not found\n"2650 client_pushes_test.go:112: Retrieved narinfo from S3:2651 StorePath: /build/TestClientFallsBackToClosures4159360235/001/store/zqgzlplpa90kcih4jixmr2zlj57af9qp-b2652 URL: nar/1zx0bvay7qfykw9gipivk5kcniszaz2yqmrh95kn450wq5l76pb5.nar.zst2653 Compression: zstd2654 NarHash: sha256:1zx0bvay7qfykw9gipivk5kcniszaz2yqmrh95kn450wq5l76pb52655 NarSize: 2162656 References: /build/TestClientFallsBackToClosures4159360235/001/store/cgi1cjpqilfkd5yq9p6fd9bj9q2xwwx9-shared-dep2657 CA: text:sha256:1vbynbs7vbp3vi63g70mmhdwywi9wlrndnyv1aw60xqf43s7rajh26582026/10/01 07:31:58 INFO Upload complete. (66ms)2659--- PASS: TestClientFallsBackToClosures (0.69s)2660--- PASS: TestReadProxyInvalidPath (0.42s)2661=== NAME TestClientPushesUseOnePush2662 client_pushes_test.go:97: Retrieved narinfo from S3:2663 StorePath: /build/TestClientPushesUseOnePush3370016239/001/store/wlacx2n2n0pg59wjs6zlmas38ikywc0z-shared-dep2664 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2665 Compression: zstd2666 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822667 NarSize: 1362668 References: 2669 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2670 client_pushes_test.go:97: Retrieved narinfo from S3:2671 StorePath: /build/TestClientPushesUseOnePush3370016239/001/store/ygzlz6drzibvssw34y7pkcq06a03k9ky-a2672 URL: nar/0c2znbk7xjv0sdmx9ibqs8j7iqgp48s2nmjp1xfqdi8g3wp4garn.nar.zst2673 Compression: zstd2674 NarHash: sha256:0c2znbk7xjv0sdmx9ibqs8j7iqgp48s2nmjp1xfqdi8g3wp4garn2675 NarSize: 2162676 References: /build/TestClientPushesUseOnePush3370016239/001/store/wlacx2n2n0pg59wjs6zlmas38ikywc0z-shared-dep2677 CA: text:sha256:1678hyxjh299a5gq1rcpx5z6ppixnbk3ih6apzjr7dc3b96mvl272678 client_pushes_test.go:97: Retrieved narinfo from S3:2679 StorePath: /build/TestClientPushesUseOnePush3370016239/001/store/5n9cbcyw9a6zjyms8sd2a3b8rxqpp5gk-b2680 URL: nar/0c2znbk7xjv0sdmx9ibqs8j7iqgp48s2nmjp1xfqdi8g3wp4garn.nar.zst2681 Compression: zstd2682 NarHash: sha256:0c2znbk7xjv0sdmx9ibqs8j7iqgp48s2nmjp1xfqdi8g3wp4garn2683 NarSize: 2162684 References: /build/TestClientPushesUseOnePush3370016239/001/store/wlacx2n2n0pg59wjs6zlmas38ikywc0z-shared-dep2685 CA: text:sha256:1678hyxjh299a5gq1rcpx5z6ppixnbk3ih6apzjr7dc3b96mvl272686--- PASS: TestClientPushesUseOnePush (0.68s)2687--- PASS: TestReadProxyConditionalGet (0.41s)26882026/10/01 07:31:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.650457ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2689--- PASS: TestReadProxy404 (0.40s)2690--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.31s)2691--- PASS: TestReadProxyHead (0.32s)2692=== NAME TestClientCADerivations2693 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2694 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2695 error: binary cache 's3://bucket52?endpoint=http://localhost:44327®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1525548121/001/store'2696 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12697--- PASS: TestClientCADerivations (0.81s)26982026/10/01 07:31:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26992026/10/01 07:31:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=371.30422ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27002026/10/01 07:31:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2701=== NAME TestOrphanedObjectsGCStressTest2702 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2703 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2704--- PASS: TestUploadHandlersRejectOversizedBody (0.25s)2705 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2706 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2707 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.77s)27082026/10/01 07:31:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=743.562536ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2709=== NAME TestOrphanedObjectsGCStressTest2710 orphaned_objects_gc_test.go:509: Stress test completed successfully:2711 orphaned_objects_gc_test.go:510: - Active objects preserved: 202712 orphaned_objects_gc_test.go:511: - Objects deleted: 2102713 orphaned_objects_gc_test.go:512: - Total GC'd: 2102714--- PASS: TestOrphanedObjectsGCStressTest (2.43s)27152026/10/01 07:32:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.505128056s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27162026/10/01 07:32:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02717=== NAME TestPinProtectsFromGC2718 client_integration_test.go:794: Pin successfully protected closure from garbage collection2719--- PASS: TestPinProtectsFromGC (2.98s)27202026/10/01 07:32:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02721=== NAME TestClientIntegration2722 client_integration_test.go:323: Objects in database after GC:2723 client_integration_test.go:323: Successfully deleted all objects with GC --force2724--- PASS: TestClientIntegration (2.67s)27252026/10/01 07:32:01 WARN Rate limiter enabled after throttle name=s3-test rate=527262026/10/01 07:32:01 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2727=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2728 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102729 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002730--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.74s)27312026/10/01 07:32:01 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-config27322026/10/01 07:32:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.11111ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27332026/10/01 07:32:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.983191ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27342026/10/01 07:32:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=766.734903ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27352026/10/01 07:32:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.522610132s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27362026/10/01 07:32:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"27372026/10/01 07:32:04 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-config27382026/10/01 07:32:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.592816ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27392026/10/01 07:32:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=406.464704ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27402026/10/01 07:32:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.208797ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27412026/10/01 07:32:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.652838573s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27422026/10/01 07:32:07 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_closures27432026/10/01 07:32:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.023356ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27442026/10/01 07:32:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.856724ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27452026/10/01 07:32:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=798.152539ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27462026/10/01 07:32:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.693473031s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2747--- PASS: TestClientErrorHandling (0.00s)2748 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)2749 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)2750 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.41s)2751PASS2752{"timestamp":"2026-10-01T07:32:11.008421756Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41720","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(401)"}27532026-10-01 07:32:11.336 UTC [129] LOG: received smart shutdown request27542026-10-01 07:32:11.341 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 127552026-10-01 07:32:11.353 UTC [134] LOG: shutting down27562026-10-01 07:32:11.354 UTC [134] LOG: checkpoint starting: shutdown immediate27572026-10-01 07:32:12.453 UTC [134] LOG: checkpoint complete: wrote 10479 buffers (64.0%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 20 recycled; write=0.257 s, sync=0.809 s, total=1.100 s; sync files=23917, longest=0.011 s, average=0.001 s; distance=325423 kB, estimate=325423 kB; lsn=0/155318F8, redo lsn=0/155318F827582026-10-01 07:32:12.530 UTC [129] LOG: database system is shut down2759Running OIDC tests...2760=== RUN TestAudienceForIssuer2761=== PAUSE TestAudienceForIssuer2762=== RUN TestGlobMatch2763=== PAUSE TestGlobMatch2764=== RUN TestValidateToken_ValidToken2765=== PAUSE TestValidateToken_ValidToken2766=== RUN TestValidateToken_WrongAudience2767=== PAUSE TestValidateToken_WrongAudience2768=== RUN TestValidateToken_Expired2769=== PAUSE TestValidateToken_Expired2770=== RUN TestValidateToken_BoundClaimsMismatch2771=== PAUSE TestValidateToken_BoundClaimsMismatch2772=== RUN TestValidateToken_BoundSubjectMismatch2773=== PAUSE TestValidateToken_BoundSubjectMismatch2774=== RUN TestValidateToken_MultipleProviders2775=== PAUSE TestValidateToken_MultipleProviders2776=== RUN TestValidateToken_NoMatchingProvider2777=== PAUSE TestValidateToken_NoMatchingProvider2778=== RUN TestValidateToken_KubernetesServiceAccount2779=== PAUSE TestValidateToken_KubernetesServiceAccount2780=== RUN TestNewValidator_KubernetesRequiresCA2781=== PAUSE TestNewValidator_KubernetesRequiresCA2782=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2783=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2784=== RUN TestPins_ReservedForMatchingRule2785=== PAUSE TestPins_ReservedForMatchingRule2786=== RUN TestPins_TopLevelShorthand2787=== PAUSE TestPins_TopLevelShorthand2788=== RUN TestPins_ConfigValidation2789=== PAUSE TestPins_ConfigValidation2790=== RUN TestScopes_LegacyProviderDefaultsToWrite2791=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2792=== RUN TestScopes_Rules2793=== PAUSE TestScopes_Rules2794=== RUN TestScopes_ConfigValidation2795=== PAUSE TestScopes_ConfigValidation2796=== CONT TestAudienceForIssuer2797=== CONT TestValidateToken_KubernetesServiceAccount2798=== CONT TestValidateToken_BoundClaimsMismatch2799--- PASS: TestAudienceForIssuer (0.00s)2800=== CONT TestValidateToken_Expired2801=== CONT TestValidateToken_WrongAudience2802=== CONT TestValidateToken_ValidToken2803=== CONT TestGlobMatch2804=== RUN TestGlobMatch/foo_foo2805=== CONT TestPins_ReservedForMatchingRule2806=== CONT TestPins_TopLevelShorthand2807=== CONT TestValidateToken_MultipleProviders2808=== CONT TestValidateToken_NoMatchingProvider2809=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2810=== CONT TestPins_ConfigValidation2811=== CONT TestNewValidator_KubernetesRequiresCA2812=== CONT TestScopes_ConfigValidation2813=== CONT TestScopes_Rules2814=== CONT TestValidateToken_BoundSubjectMismatch2815=== CONT TestScopes_LegacyProviderDefaultsToWrite2816=== PAUSE TestGlobMatch/foo_foo2817=== RUN TestGlobMatch/foo_bar2818=== PAUSE TestGlobMatch/foo_bar2819=== RUN TestGlobMatch/*_2820=== PAUSE TestGlobMatch/*_2821=== RUN TestGlobMatch/*_anything2822=== PAUSE TestGlobMatch/*_anything2823=== RUN TestGlobMatch/foo*_foo2824=== PAUSE TestGlobMatch/foo*_foo2825=== RUN TestGlobMatch/foo*_foobar2826=== PAUSE TestGlobMatch/foo*_foobar2827=== RUN TestGlobMatch/foo*_bar2828=== PAUSE TestGlobMatch/foo*_bar2829=== RUN TestGlobMatch/*bar_bar2830=== PAUSE TestGlobMatch/*bar_bar2831=== RUN TestGlobMatch/*bar_foobar2832=== PAUSE TestGlobMatch/*bar_foobar2833=== RUN TestGlobMatch/*bar_foo2834=== PAUSE TestGlobMatch/*bar_foo2835=== RUN TestGlobMatch/foo*bar_foobar2836=== PAUSE TestGlobMatch/foo*bar_foobar2837=== RUN TestGlobMatch/foo*bar_foo123bar2838=== PAUSE TestGlobMatch/foo*bar_foo123bar2839=== RUN TestGlobMatch/foo*bar_foobarbaz2840=== PAUSE TestGlobMatch/foo*bar_foobarbaz2841=== RUN TestGlobMatch/*/*_foo/bar2842=== PAUSE TestGlobMatch/*/*_foo/bar2843=== RUN TestGlobMatch/*/*_foo2844=== PAUSE TestGlobMatch/*/*_foo2845=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2846=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2847=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02848=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02849=== RUN TestGlobMatch/refs/*/main_refs/heads/main2850=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2851=== RUN TestGlobMatch/fo?_foo2852=== PAUSE TestGlobMatch/fo?_foo2853=== RUN TestGlobMatch/fo?_fo2854=== PAUSE TestGlobMatch/fo?_fo2855=== RUN TestGlobMatch/fo?_fooo2856=== PAUSE TestGlobMatch/fo?_fooo2857=== RUN TestGlobMatch/?oo_foo2858=== PAUSE TestGlobMatch/?oo_foo2859=== RUN TestGlobMatch/?oo_boo2860=== PAUSE TestGlobMatch/?oo_boo2861=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2862=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2863=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2864=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2865=== CONT TestGlobMatch/foo_foo2866=== CONT TestGlobMatch/*/*_foo/bar2867=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2868=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2869=== CONT TestGlobMatch/?oo_boo2870=== CONT TestGlobMatch/?oo_foo2871=== CONT TestGlobMatch/fo?_fooo2872=== CONT TestGlobMatch/*bar_bar2873=== CONT TestGlobMatch/foo*_bar2874=== CONT TestGlobMatch/foo*_foobar2875=== CONT TestGlobMatch/foo*bar_foobarbaz2876=== CONT TestGlobMatch/foo*bar_foo123bar2877=== CONT TestGlobMatch/foo*bar_foobar2878=== CONT TestGlobMatch/*bar_foo2879=== CONT TestGlobMatch/*bar_foobar2880=== CONT TestGlobMatch/fo?_fo2881=== CONT TestGlobMatch/foo*_foo2882=== CONT TestGlobMatch/*_anything2883=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02884=== CONT TestGlobMatch/fo?_foo2885=== CONT TestGlobMatch/refs/*/main_refs/heads/main2886=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2887=== CONT TestGlobMatch/*/*_foo2888=== CONT TestGlobMatch/*_2889--- PASS: TestPins_ConfigValidation (0.00s)2890=== CONT TestGlobMatch/foo_bar2891--- PASS: TestScopes_ConfigValidation (0.00s)2892--- PASS: TestGlobMatch (0.00s)2893 --- PASS: TestGlobMatch/foo_foo (0.00s)2894 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2895 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2896 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2897 --- PASS: TestGlobMatch/?oo_boo (0.00s)2898 --- PASS: TestGlobMatch/?oo_foo (0.00s)2899 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2900 --- PASS: TestGlobMatch/*bar_bar (0.00s)2901 --- PASS: TestGlobMatch/foo*_bar (0.00s)2902 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2903 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2904 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2905 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2906 --- PASS: TestGlobMatch/*bar_foo (0.00s)2907 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2908 --- PASS: TestGlobMatch/foo*_foo (0.00s)2909 --- PASS: TestGlobMatch/*_anything (0.00s)2910 --- PASS: TestGlobMatch/fo?_fo (0.00s)2911 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2912 --- PASS: TestGlobMatch/fo?_foo (0.00s)2913 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2914 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2915 --- PASS: TestGlobMatch/*/*_foo (0.00s)2916 --- PASS: TestGlobMatch/*_ (0.00s)2917 --- PASS: TestGlobMatch/foo_bar (0.00s)29182026/10/01 07:32:14 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:410252919--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)29202026/10/01 07:32:14 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232921--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)29222026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33827/oidc2923--- PASS: TestValidateToken_ValidToken (0.06s)29242026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36821/oidc29252026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46321/oidc29262026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36393/oidc2927--- PASS: TestValidateToken_WrongAudience (0.06s)2928--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)2929--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)29302026/10/01 07:32:14 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45459/oidc29312026/10/01 07:32:14 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44665/oidc29322026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44311/oidc2933--- PASS: TestValidateToken_MultipleProviders (0.07s)2934--- PASS: TestValidateToken_Expired (0.08s)29352026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43175/oidc2936--- PASS: TestPins_ReservedForMatchingRule (0.08s)29372026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37517/oidc2938--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)29392026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45915/oidc2940--- PASS: TestPins_TopLevelShorthand (0.11s)29412026/10/01 07:32:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39977/oidc2942--- PASS: TestScopes_Rules (0.13s)29432026/10/01 07:32:14 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42025/oidc2944--- PASS: TestValidateToken_NoMatchingProvider (0.15s)29452026/10/01 07:32:14 http: TLS handshake error from 127.0.0.1:48608: remote error: tls: bad certificate2946--- PASS: TestNewValidator_KubernetesRequiresCA (0.17s)2947PASS2948Running hook tests...2949=== RUN TestSendPathsEmpty2950=== PAUSE TestSendPathsEmpty2951=== RUN TestQueueEnqueueAndFetch2952=== PAUSE TestQueueEnqueueAndFetch2953=== RUN TestQueueDeduplication2954=== PAUSE TestQueueDeduplication2955=== RUN TestQueueRemove2956=== PAUSE TestQueueRemove2957=== RUN TestQueueFetchBatchLimit2958=== PAUSE TestQueueFetchBatchLimit2959=== RUN TestQueueRetryMovesToBack2960=== PAUSE TestQueueRetryMovesToBack2961=== RUN TestQueueFetchRemoveLifecycle2962=== PAUSE TestQueueFetchRemoveLifecycle2963=== RUN TestQueueConcurrentWriters2964=== PAUSE TestQueueConcurrentWriters2965=== RUN TestQueueRemoveLargeClosure2966=== PAUSE TestQueueRemoveLargeClosure2967=== RUN TestServerClientIntegration2968=== PAUSE TestServerClientIntegration2969=== RUN TestServerQueueError2970=== PAUSE TestServerQueueError2971=== RUN TestGetListenerSocketActivation2972 server_test.go:210: === RUN TestGetListenerSocketActivation2973 --- PASS: TestGetListenerSocketActivation (0.00s)2974 PASS2975 2976--- PASS: TestGetListenerSocketActivation (0.01s)2977=== RUN TestDrainIsolatesPoisonPath2978=== PAUSE TestDrainIsolatesPoisonPath2979=== RUN TestRunNotBlockedByPoisonHead2980=== PAUSE TestRunNotBlockedByPoisonHead2981=== RUN TestDrainGivesUpWhenServerDown2982=== PAUSE TestDrainGivesUpWhenServerDown2983=== RUN TestFailedPathPrunedByLaterClosure2984=== PAUSE TestFailedPathPrunedByLaterClosure2985=== RUN TestWorkerUploadsAndRemoves2986=== PAUSE TestWorkerUploadsAndRemoves2987=== RUN TestWorkerSkipsGCdPaths2988=== PAUSE TestWorkerSkipsGCdPaths2989=== RUN TestWorkerPrunesClosureDeps2990=== PAUSE TestWorkerPrunesClosureDeps2991=== RUN TestDrainTimeout2992=== PAUSE TestDrainTimeout2993=== CONT TestSendPathsEmpty2994=== CONT TestServerQueueError2995=== CONT TestQueueRemove2996=== CONT TestQueueRetryMovesToBack2997=== CONT TestServerClientIntegration2998--- PASS: TestSendPathsEmpty (0.00s)2999=== CONT TestQueueRemoveLargeClosure3000=== CONT TestQueueDeduplication3001=== CONT TestQueueConcurrentWriters30022026/10/01 07:32:14 ERROR Failed to queue paths error="permission denied" count=13003=== CONT TestQueueEnqueueAndFetch3004=== CONT TestWorkerUploadsAndRemoves3005--- PASS: TestServerQueueError (0.00s)3006=== CONT TestDrainTimeout3007=== CONT TestWorkerPrunesClosureDeps3008=== CONT TestQueueFetchRemoveLifecycle3009=== CONT TestWorkerSkipsGCdPaths3010=== CONT TestDrainGivesUpWhenServerDown3011=== CONT TestQueueFetchBatchLimit3012=== CONT TestFailedPathPrunedByLaterClosure3013=== CONT TestRunNotBlockedByPoisonHead3014=== CONT TestDrainIsolatesPoisonPath3015--- PASS: TestServerClientIntegration (0.00s)30162026/10/01 07:32:14 INFO Uploading batch count=430172026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=430182026/10/01 07:32:14 INFO Upload queue status pending=230192026/10/01 07:32:14 INFO Uploading batch count=230202026/10/01 07:32:14 INFO Uploading batch count=230212026/10/01 07:32:14 INFO Upload queue status pending=230222026/10/01 07:32:14 INFO Upload queue status pending=330232026/10/01 07:32:14 INFO Uploading batch count=130242026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=130252026/10/01 07:32:14 INFO Uploading batch count=130262026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=130272026/10/01 07:32:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3624021408/002/bbb30282026/10/01 07:32:14 INFO Uploading batch count=13029--- PASS: TestQueueFetchBatchLimit (0.02s)3030--- PASS: TestQueueRemove (0.02s)3031--- PASS: TestQueueEnqueueAndFetch (0.02s)30322026/10/01 07:32:14 INFO Upload queue status pending=23033--- PASS: TestQueueDeduplication (0.02s)30342026/10/01 07:32:14 INFO Uploading batch count=130352026/10/01 07:32:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths880144734/002/nonexistent30362026/10/01 07:32:14 INFO Uploading batch count=230372026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=230382026/10/01 07:32:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown316834646/002/a30392026/10/01 07:32:14 INFO Uploading batch count=130402026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=130412026/10/01 07:32:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown316834646/002/b30422026/10/01 07:32:14 INFO Uploading batch count=130432026/10/01 07:32:14 INFO Uploading batch count=13044--- PASS: TestQueueRetryMovesToBack (0.03s)3045--- PASS: TestQueueFetchRemoveLifecycle (0.02s)30462026/10/01 07:32:14 INFO Uploading batch count=130472026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=130482026/10/01 07:32:14 INFO Uploading batch count=230492026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=230502026/10/01 07:32:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown316834646/002/c30512026/10/01 07:32:14 INFO Uploading batch count=130522026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=130532026/10/01 07:32:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown316834646/002/d3054--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)30552026/10/01 07:32:14 ERROR Drain finished with paths left in queue remaining=130562026/10/01 07:32:14 INFO Uploading batch count=230572026/10/01 07:32:14 ERROR Upload failed error="upload failed" count=230582026/10/01 07:32:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown316834646/002/e30592026/10/01 07:32:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown316834646/002/f3060--- PASS: TestDrainIsolatesPoisonPath (0.02s)30612026/10/01 07:32:14 ERROR Drain finished with paths left in queue remaining=103062--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3063--- PASS: TestWorkerUploadsAndRemoves (0.04s)3064--- PASS: TestWorkerPrunesClosureDeps (0.04s)3065--- PASS: TestWorkerSkipsGCdPaths (0.04s)3066--- PASS: TestQueueRemoveLargeClosure (0.09s)30672026/10/01 07:32:14 ERROR Upload failed error="context deadline exceeded" count=230682026/10/01 07:32:14 ERROR Drain finished with paths left in queue remaining=43069--- PASS: TestDrainTimeout (0.22s)3070--- PASS: TestQueueConcurrentWriters (0.38s)30712026/10/01 07:32:15 INFO Uploading batch count=130722026/10/01 07:32:15 INFO Uploading batch count=130732026/10/01 07:32:15 INFO Uploading batch count=130742026/10/01 07:32:15 ERROR Upload failed error="upload failed" count=130752026/10/01 07:32:15 INFO Uploading batch count=130762026/10/01 07:32:15 ERROR Upload failed error="upload failed" count=130772026/10/01 07:32:15 INFO Uploading batch count=130782026/10/01 07:32:15 ERROR Upload failed error="upload failed" count=130792026/10/01 07:32:15 INFO Uploading batch count=130802026/10/01 07:32:15 ERROR Upload failed error="upload failed" count=130812026/10/01 07:32:15 ERROR Drain finished with paths left in queue remaining=13082--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3083PASS