niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #206
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathCaseHackMatchesNix13--- PASS: TestDumpPathCaseHackMatchesNix (9.15s)14=== RUN TestDumpPathCaseHackCollision15--- PASS: TestDumpPathCaseHackCollision (0.00s)16=== RUN TestDumpPathMatchesNix17=== PAUSE TestDumpPathMatchesNix18=== RUN TestDumpPathSingleFile19=== PAUSE TestDumpPathSingleFile20=== RUN TestDumpPathWriterError21=== PAUSE TestDumpPathWriterError22=== RUN TestEncodeNixBase3223=== PAUSE TestEncodeNixBase3224=== RUN TestEncodeNixBase32WithRealHash25=== PAUSE TestEncodeNixBase32WithRealHash26=== RUN TestConvertHashToNix3227=== PAUSE TestConvertHashToNix3228=== RUN TestGetStorePathHash29=== PAUSE TestGetStorePathHash30=== RUN TestPathInfoHashCompatibility31=== PAUSE TestPathInfoHashCompatibility32=== RUN TestParsePathInfoJSON33=== PAUSE TestParsePathInfoJSON34=== RUN TestParsePathInfoJSONMultiplePaths35=== PAUSE TestParsePathInfoJSONMultiplePaths36=== RUN TestPathInfoCACompatibility37=== PAUSE TestPathInfoCACompatibility38=== RUN TestRateLimiterFeedback39=== PAUSE TestRateLimiterFeedback40=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess41=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== RUN TestResolveStorePath43=== PAUSE TestResolveStorePath44=== RUN TestDoWithRetry_BodyReplayedViaGetBody45=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody46=== RUN TestShellSplit47=== PAUSE TestShellSplit48=== RUN TestShellSplitErrors49=== PAUSE TestShellSplitErrors50=== RUN TestStreamPushReportsEveryPath51=== PAUSE TestStreamPushReportsEveryPath52=== RUN TestStreamPushBatchesUnderLoad53=== PAUSE TestStreamPushBatchesUnderLoad54=== RUN TestStreamPushIsolatesFailures55=== PAUSE TestStreamPushIsolatesFailures56=== RUN TestStreamPushGivesUpOnDeadServer57=== PAUSE TestStreamPushGivesUpOnDeadServer58=== RUN TestSetClientTLS59=== PAUSE TestSetClientTLS60=== RUN TestSetClientTLSDoesNotMutateDefaultTransport61=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport62=== RUN TestSetClientTLSErrors63=== PAUSE TestSetClientTLSErrors64=== RUN TestStaticToken65=== PAUSE TestStaticToken66=== RUN TestFileTokenReadsAndCaches67=== PAUSE TestFileTokenReadsAndCaches68=== RUN TestFileTokenMissing69=== PAUSE TestFileTokenMissing70=== RUN TestFileTokenEmpty71=== PAUSE TestFileTokenEmpty72=== RUN TestScriptTokenNoExpiryRerunsEveryCall73=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall74=== RUN TestScriptTokenCachesUntilRefresh75=== PAUSE TestScriptTokenCachesUntilRefresh76=== RUN TestScriptTokenEmptyToken77=== PAUSE TestScriptTokenEmptyToken78=== RUN TestScriptTokenBadJSON79=== PAUSE TestScriptTokenBadJSON80=== RUN TestScriptTokenScriptFails81=== PAUSE TestScriptTokenScriptFails82=== RUN TestScriptTokenEmptyCommand83=== PAUSE TestScriptTokenEmptyCommand84=== CONT TestDoServerRequestAttachesToken85=== CONT TestShellSplit86=== CONT TestFileTokenReadsAndCaches87=== CONT TestStreamPushGivesUpOnDeadServer88--- PASS: TestShellSplit (0.00s)89=== CONT TestSetClientTLSDoesNotMutateDefaultTransport90=== CONT TestShellSplitErrors91--- PASS: TestShellSplitErrors (0.00s)92=== CONT TestScriptTokenEmptyToken932026/09/15 08:17:59 ERROR Upload failed error="connection refused" count=20942026/09/15 08:17:59 ERROR Server seems unavailable, giving up on batch untried=1795=== CONT TestStaticToken96=== CONT TestSetClientTLSErrors97=== CONT TestDoWithRetry_BodyReplayedViaGetBody98=== CONT TestStreamPushIsolatesFailures99=== CONT TestStreamPushBatchesUnderLoad1002026/09/15 08:17:59 ERROR Upload failed error="bad path" count=3101=== CONT TestResolveStorePath102=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess103=== RUN TestSetClientTLSErrors/missing_cert_file104=== PAUSE TestSetClientTLSErrors/missing_cert_file105=== RUN TestSetClientTLSErrors/missing_key_file106=== PAUSE TestSetClientTLSErrors/missing_key_file107=== RUN TestSetClientTLSErrors/missing_ca_file1082026/09/15 08:17:59 WARN Rate limiter enabled after throttle name=server-test rate=5109=== PAUSE TestSetClientTLSErrors/missing_ca_file110=== RUN TestSetClientTLSErrors/invalid_ca_file111=== PAUSE TestSetClientTLSErrors/invalid_ca_file112=== CONT TestRateLimiterFeedback113=== RUN TestRateLimiterFeedback/429_enables_limiter114=== PAUSE TestRateLimiterFeedback/429_enables_limiter115=== RUN TestRateLimiterFeedback/503_enables_limiter116=== PAUSE TestRateLimiterFeedback/503_enables_limiter117=== CONT TestStreamPushReportsEveryPath118--- PASS: TestStaticToken (0.00s)119--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)120--- PASS: TestStreamPushIsolatesFailures (0.00s)121--- PASS: TestFileTokenReadsAndCaches (0.00s)122=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter123=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter124=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter125=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter126=== CONT TestConvertHashToNix32127=== RUN TestConvertHashToNix32/SRI_format_to_Nix32128=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32129=== RUN TestConvertHashToNix32/already_Nix32_format130=== PAUSE TestConvertHashToNix32/already_Nix32_format131=== RUN TestConvertHashToNix32/invalid_format132=== PAUSE TestConvertHashToNix32/invalid_format133=== CONT TestPathInfoCACompatibility134=== RUN TestPathInfoCACompatibility/null_ca_field135=== PAUSE TestPathInfoCACompatibility/null_ca_field136=== RUN TestPathInfoCACompatibility/old_string_format_-_text137=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text138=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive139=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive140--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)141--- PASS: TestStreamPushReportsEveryPath (0.00s)142=== CONT TestParsePathInfoJSON143=== RUN TestParsePathInfoJSON/Nix_format144=== PAUSE TestParsePathInfoJSON/Nix_format145=== RUN TestParsePathInfoJSON/Lix_format146=== PAUSE TestParsePathInfoJSON/Lix_format147=== RUN TestParsePathInfoJSON/empty_input148=== CONT TestParsePathInfoJSONMultiplePaths149=== RUN TestPathInfoCACompatibility/new_structured_format_-_text150=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text151=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method152=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method153=== CONT TestPathInfoHashCompatibility154=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon157=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1582026/09/15 08:17:59 WARN Rate limiter enabled after throttle name=server-test rate=5159=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI160=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI161=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512162=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512163=== CONT TestGetStorePathHash164=== RUN TestGetStorePathHash/valid_store_path165=== PAUSE TestGetStorePathHash/valid_store_path1662026/09/15 08:17:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56754167=== RUN TestGetStorePathHash/basename_without_hyphen_should_error168--- PASS: TestResolveStorePath (0.00s)169=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error170=== CONT TestDumpPathMatchesNix171=== CONT TestEncodeNixBase32WithRealHash172--- PASS: TestEncodeNixBase32WithRealHash (0.00s)173=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error174=== CONT TestEncodeNixBase32175=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error176=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths177=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error1782026/09/15 08:17:59 WARN Rate limiter backed off name=server-test rate=5179=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error1802026/09/15 08:17:59 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56754181=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths182=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths183=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths184=== CONT TestDumpPathWriterError185=== CONT TestDumpPathSingleFile186--- PASS: TestDoServerRequestAttachesToken (0.00s)187=== CONT TestSetClientTLS188=== RUN TestEncodeNixBase32/test_string_hash189=== PAUSE TestEncodeNixBase32/test_string_hash190=== RUN TestEncodeNixBase32/empty_input191=== PAUSE TestEncodeNixBase32/empty_input192=== PAUSE TestParsePathInfoJSON/empty_input193=== RUN TestParsePathInfoJSON/whitespace_only194=== PAUSE TestParsePathInfoJSON/whitespace_only195=== RUN TestParsePathInfoJSON/invalid_JSON196=== PAUSE TestParsePathInfoJSON/invalid_JSON197=== CONT TestScriptTokenEmptyCommand198=== CONT TestScriptTokenCachesUntilRefresh199--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)200--- PASS: TestScriptTokenEmptyCommand (0.00s)201=== CONT TestScriptTokenNoExpiryRerunsEveryCall202=== CONT TestScriptTokenScriptFails203=== RUN TestSetClientTLS/rejects_connection_without_client_cert204=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert205=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA206=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA207=== RUN TestSetClientTLS/preserves_debug_logging_transport208=== PAUSE TestSetClientTLS/preserves_debug_logging_transport209=== CONT TestScriptTokenBadJSON210--- PASS: TestScriptTokenEmptyToken (0.01s)211=== CONT TestFileTokenEmpty212--- PASS: TestScriptTokenScriptFails (0.01s)213=== CONT TestFileTokenMissing214--- PASS: TestFileTokenMissing (0.00s)215=== CONT TestPartSizeForNAR216=== RUN TestPartSizeForNAR/zero_stays_at_minimum217=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum218=== RUN TestPartSizeForNAR/small_stays_at_minimum219=== PAUSE TestPartSizeForNAR/small_stays_at_minimum220=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum221=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum222=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts223=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts224=== RUN TestPartSizeForNAR/1_TiB225=== PAUSE TestPartSizeForNAR/1_TiB226=== RUN TestPartSizeForNAR/5_TiB_S3_max_object227=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object228=== RUN TestPartSizeForNAR/capped_at_5_GiB229=== PAUSE TestPartSizeForNAR/capped_at_5_GiB230--- PASS: TestFileTokenEmpty (0.00s)231=== CONT TestUploadMultipart_SupersededByPeer232=== RUN TestUploadMultipart_SupersededByPeer/exists233=== PAUSE TestUploadMultipart_SupersededByPeer/exists234=== RUN TestUploadMultipart_SupersededByPeer/missing235=== PAUSE TestUploadMultipart_SupersededByPeer/missing236=== CONT TestFilterOversizedClosures237=== RUN TestFilterOversizedClosures/no_limit_keeps_everything238=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything239=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== RUN TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestFilterOversizedClosures/all_closures_skipped243=== CONT TestCaseHackSuffix244=== CONT TestSetClientTLSErrors/missing_cert_file245=== CONT TestSetClientTLSErrors/missing_ca_file246=== CONT TestSetClientTLSErrors/invalid_ca_file247=== CONT TestSetClientTLSErrors/missing_key_file248=== CONT TestRateLimiterFeedback/429_enables_limiter249--- PASS: TestSetClientTLSErrors (0.00s)250 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)251 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)252 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)253 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)2542026/09/15 08:17:59 WARN Rate limiter enabled after throttle name=server-test rate=52552026/09/15 08:17:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:567602562026/09/15 08:17:59 WARN Rate limiter backed off name=server-test rate=5257=== CONT TestConvertHashToNix32/SRI_format_to_Nix32258=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter259=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter260=== CONT TestConvertHashToNix32/invalid_format261=== CONT TestRateLimiterFeedback/503_enables_limiter2622026/09/15 08:17:59 WARN Rate limiter enabled after throttle name=server-test rate=52632026/09/15 08:17:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:567662642026/09/15 08:17:59 WARN Rate limiter backed off name=server-test rate=5265--- PASS: TestRateLimiterFeedback (0.00s)266 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)267 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)268 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)269 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)270=== CONT TestConvertHashToNix32/already_Nix32_format271--- PASS: TestConvertHashToNix32 (0.00s)272 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)273 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)274 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)275=== CONT TestPathInfoCACompatibility/null_ca_field276=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)277=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method278=== CONT TestPathInfoCACompatibility/new_structured_format_-_text279=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive280=== CONT TestPathInfoCACompatibility/old_string_format_-_text281--- PASS: TestPathInfoCACompatibility (0.00s)282 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)283 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)284 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)285 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)286 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)287=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI288=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon289=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512290--- PASS: TestPathInfoHashCompatibility (0.00s)291 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)292 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)293 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)294 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)295=== CONT TestGetStorePathHash/valid_store_path296=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths297=== CONT TestGetStorePathHash/basename_without_hyphen_should_error298=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error299=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error300--- PASS: TestGetStorePathHash (0.00s)301 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)302 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)303 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)304 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)305=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths306--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)307 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)308 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)309--- PASS: TestScriptTokenBadJSON (0.02s)310=== CONT TestEncodeNixBase32/test_string_hash311=== CONT TestParsePathInfoJSON/Nix_format312=== CONT TestParsePathInfoJSON/invalid_JSON313=== CONT TestParsePathInfoJSON/whitespace_only314=== CONT TestParsePathInfoJSON/empty_input315=== CONT TestParsePathInfoJSON/Lix_format316--- PASS: TestParsePathInfoJSON (0.00s)317 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)318 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)319 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)320 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)321 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)322=== CONT TestEncodeNixBase32/empty_input323--- PASS: TestEncodeNixBase32 (0.00s)324 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)325 --- PASS: TestEncodeNixBase32/empty_input (0.00s)326=== CONT TestSetClientTLS/rejects_connection_without_client_cert327=== CONT TestSetClientTLS/preserves_debug_logging_transport328=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA329=== CONT TestPartSizeForNAR/zero_stays_at_minimum330=== CONT TestPartSizeForNAR/capped_at_5_GiB331=== CONT TestPartSizeForNAR/5_TiB_S3_max_object332=== CONT TestPartSizeForNAR/1_TiB333=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts334=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum335=== CONT TestPartSizeForNAR/small_stays_at_minimum336--- PASS: TestPartSizeForNAR (0.00s)337 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)338 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)339 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)340 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)341 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)342 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)343 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)344=== CONT TestUploadMultipart_SupersededByPeer/exists345=== CONT TestFilterOversizedClosures/no_limit_keeps_everything346=== CONT TestUploadMultipart_SupersededByPeer/missing347--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)348 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)349 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)350=== CONT TestFilterOversizedClosures/all_closures_skipped3512026/09/15 08:17:59 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=50352=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3532026/09/15 08:17:59 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=2000354--- PASS: TestFilterOversizedClosures (0.00s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)357 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3582026/09/15 08:17:59 http: TLS handshake error from 127.0.0.1:56768: read tcp 127.0.0.1:56759->127.0.0.1:56768: use of closed network connection359--- PASS: TestSetClientTLS (0.00s)360 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)361 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)362 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)363--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)364--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)365--- PASS: TestDumpPathWriterError (0.05s)366--- PASS: TestDumpPathSingleFile (0.06s)367--- PASS: TestCaseHackSuffix (0.06s)368--- PASS: TestDumpPathMatchesNix (0.08s)369--- PASS: TestStreamPushBatchesUnderLoad (0.10s)370--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)371PASS372Running server tests...373The files belonging to this database system will be owned by user "_nixbld10".374This user must also own the server process.375376The database cluster will be initialized with locale "C".377The default database encoding has accordingly been set to "SQL_ASCII".378The default text search configuration will be set to "english".379380Data page checksums are enabled.381382creating directory /nix/var/nix/builds/nix-47169-961580207/postgres527802174/data ... ok383creating subdirectories ... ok384selecting dynamic shared memory implementation ... posix385selecting default "max_connections" ... 100386selecting default "shared_buffers" ... 128MB387selecting default time zone ... UTC388creating configuration files ... ok389running bootstrap script ... ok390performing post-bootstrap initialization ... ok391syncing data to disk ... ok392393initdb: warning: enabling "trust" authentication for local connections394initdb: 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.395396Success. You can now start the database server using:397398 pg_ctl -D /nix/var/nix/builds/nix-47169-961580207/postgres527802174/data -l logfile start3994002026-09-15 08:18:03.389 UTC [63092] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4012026-09-15 08:18:03.389 UTC [63092] LOG: listening on Unix socket "/nix/var/nix/builds/nix-47169-961580207/postgres527802174/.s.PGSQL.5432"4022026-09-15 08:18:03.391 UTC [63104] LOG: database system was shut down at 2026-09-15 08:18:03 UTC4032026-09-15 08:18:03.392 UTC [63092] LOG: database system is ready to accept connections404/nix/var/nix/builds/nix-47169-961580207/postgres527802174:5432 - accepting connections405=== RUN TestService_AuthMiddleware406=== PAUSE TestService_AuthMiddleware407=== RUN TestService_AuthMiddleware_MTLSProxyHeader408=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader409=== RUN TestService_AuthMiddleware_MTLSBoundSubjects410=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects411=== RUN TestService_ReadAuthMiddleware412=== PAUSE TestService_ReadAuthMiddleware413=== RUN TestService_AuthMiddleware_OIDC414=== PAUSE TestService_AuthMiddleware_OIDC415=== RUN TestService_RequireScope_OIDC416=== PAUSE TestService_RequireScope_OIDC417=== RUN TestService_ReadScope_PublicByDefault418=== PAUSE TestService_ReadScope_PublicByDefault419=== RUN TestCacheConfigHandler420=== PAUSE TestCacheConfigHandler421=== RUN TestCacheStatsHandler422=== PAUSE TestCacheStatsHandler423=== RUN TestClientCADerivations424=== PAUSE TestClientCADerivations425=== RUN TestClientErrorHandling426=== PAUSE TestClientErrorHandling427=== RUN TestClientIntegration428=== PAUSE TestClientIntegration429=== RUN TestClientMultipleUploads430=== PAUSE TestClientMultipleUploads431=== RUN TestClientWithDependencies432=== PAUSE TestClientWithDependencies433=== RUN TestPinProtectsFromGC434=== PAUSE TestPinProtectsFromGC435=== RUN TestResolveDBConnectionString436=== PAUSE TestResolveDBConnectionString437=== RUN TestGCAdvisoryLockBlocksConcurrentRun4382026-09-15 08:18:05.758 UTC [64039] ERROR: relation "goose_db_version" does not exist at character 364392026-09-15 08:18:05.758 UTC [64039] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4402026/09/15 08:18:05 OK 20241026095416_initial_model.sql (3.39ms)4412026/09/15 08:18:05 OK 20251210153512_drop_unused_gin_index.sql (668.71µs)4422026/09/15 08:18:05 OK 20251218171726_add_pins.sql (933.08µs)4432026/09/15 08:18:05 OK 20260628120000_add_object_size_and_stats.sql (904.04µs)4442026/09/15 08:18:05 goose: successfully migrated database to version: 202606281200004452026/09/15 08:18:05 OK 1_commit_pending_closure.sql (941.67µs)4462026/09/15 08:18:05 OK 2_object_stats_trigger.sql (259.42µs)4472026/09/15 08:18:05 goose: up to current file version: 2448--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.37s)449=== RUN TestGCBugBareHashReferences450=== PAUSE TestGCBugBareHashReferences451=== RUN TestGCMetrics452=== PAUSE TestGCMetrics453=== RUN TestGCTaskStore_StartNew454=== PAUSE TestGCTaskStore_StartNew455=== RUN TestGCTaskStore_DeduplicateSameParams456=== PAUSE TestGCTaskStore_DeduplicateSameParams457=== RUN TestGCTaskStore_ConflictDifferentParams458=== PAUSE TestGCTaskStore_ConflictDifferentParams459=== RUN TestGCTaskStore_GetEmpty460=== PAUSE TestGCTaskStore_GetEmpty461=== RUN TestGCTaskStore_GetReturnsLatest462=== PAUSE TestGCTaskStore_GetReturnsLatest463=== RUN TestGCTaskStore_CompletedAllowsNewTask464=== PAUSE TestGCTaskStore_CompletedAllowsNewTask465=== RUN TestGCTaskStore_PhaseUpdates466=== PAUSE TestGCTaskStore_PhaseUpdates467=== RUN TestGCTaskStore_Fail468=== PAUSE TestGCTaskStore_Fail469=== RUN TestGracefulShutdownDrainsInflight470=== PAUSE TestGracefulShutdownDrainsInflight471=== RUN TestService_healthCheckHandler472=== PAUSE TestService_healthCheckHandler473=== RUN TestService_readinessHandler474=== PAUSE TestService_readinessHandler475=== RUN TestGenerateLandingPage476=== PAUSE TestGenerateLandingPage477=== RUN TestCacheConfigHandlerMaxNarSize478=== PAUSE TestCacheConfigHandlerMaxNarSize479=== RUN TestCreatePendingClosureRejectsOversizedNAR480=== PAUSE TestCreatePendingClosureRejectsOversizedNAR481=== RUN TestNARDeduplicationMetadataUploadBug482=== PAUSE TestNARDeduplicationMetadataUploadBug483=== RUN TestMetricsInventory484=== PAUSE TestMetricsInventory485=== RUN TestService_NativeMTLS486=== PAUSE TestService_NativeMTLS487=== RUN TestServerTLSConfig488=== PAUSE TestServerTLSConfig489=== RUN TestMultipartCleanup490=== PAUSE TestMultipartCleanup491=== RUN TestObjectStatsTrigger492=== PAUSE TestObjectStatsTrigger493=== RUN TestOrphanedObjectsGC494=== PAUSE TestOrphanedObjectsGC495=== RUN TestOrphanedObjectsGCStressTest496=== PAUSE TestOrphanedObjectsGCStressTest497=== RUN TestResurrectedObjectNotDeleted498=== PAUSE TestResurrectedObjectNotDeleted499=== RUN TestParseSingleRange500=== PAUSE TestParseSingleRange501=== RUN TestIsValidCachePath502=== PAUSE TestIsValidCachePath503=== RUN TestReadProxyNarinfo504=== PAUSE TestReadProxyNarinfo505=== RUN TestReadProxyNarinfoAlreadyDecompressed506=== PAUSE TestReadProxyNarinfoAlreadyDecompressed507=== RUN TestReadProxyNarStreaming508=== PAUSE TestReadProxyNarStreaming509=== RUN TestReadProxy404510=== PAUSE TestReadProxy404511=== RUN TestReadProxyInvalidPath512=== PAUSE TestReadProxyInvalidPath513=== RUN TestReadProxyHead514=== PAUSE TestReadProxyHead515=== RUN TestReadProxyConditionalGet516=== PAUSE TestReadProxyConditionalGet517=== RUN TestReadProxyRootRedirectsToIndexHTML518=== PAUSE TestReadProxyRootRedirectsToIndexHTML519=== RUN TestReadProxyDisabled520=== PAUSE TestReadProxyDisabled521=== RUN TestReadRedirectNar522=== PAUSE TestReadRedirectNar523=== RUN TestReadRedirectKeepsNarinfoProxied524=== PAUSE TestReadRedirectKeepsNarinfoProxied525=== RUN TestReadProxyRangeRequest526=== PAUSE TestReadProxyRangeRequest527=== RUN TestReadRedirectUsesPublicS3URL528=== PAUSE TestReadRedirectUsesPublicS3URL529=== RUN TestRedundantMultipartUpload530=== PAUSE TestRedundantMultipartUpload531=== RUN TestCompleteMultipartUpload_ErrorButObjectExists532=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists533=== RUN TestCompletedNarNotReofferedAcrossClosures534=== PAUSE TestCompletedNarNotReofferedAcrossClosures535=== RUN TestPresignedUploadRegisteredBeforeCommit536=== PAUSE TestPresignedUploadRegisteredBeforeCommit537=== RUN TestService_Rustfstest538=== PAUSE TestService_Rustfstest539=== RUN TestParseSize540=== PAUSE TestParseSize541=== RUN TestSkippedUploadsHandler542=== PAUSE TestSkippedUploadsHandler543=== RUN TestSystemdListenerNotActivated544--- PASS: TestSystemdListenerNotActivated (0.00s)545=== RUN TestWatchdogBeatsWhenHealthy546--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)547=== RUN TestWatchdogSkipsWhenUnhealthy5482026/09/15 08:18:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5492026/09/15 08:18:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5502026/09/15 08:18:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5512026/09/15 08:18:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5522026/09/15 08:18:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5532026/09/15 08:18:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5542026/09/15 08:18:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5552026/09/15 08:18:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5562026/09/15 08:18:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"557--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)558=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle559=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle560=== RUN TestProxyWriteTimeout561=== PAUSE TestProxyWriteTimeout562=== RUN TestIsValidUploadKey563=== PAUSE TestIsValidUploadKey564=== RUN TestUploadHandlersRejectInvalidKeys565=== PAUSE TestUploadHandlersRejectInvalidKeys566=== RUN TestUploadHandlersRejectOversizedBody567=== PAUSE TestUploadHandlersRejectOversizedBody568=== RUN TestService_cleanupPendingClosuresHandler569=== PAUSE TestService_cleanupPendingClosuresHandler570=== RUN TestService_createPendingClosureHandler571=== PAUSE TestService_createPendingClosureHandler572=== RUN TestService_verifyS3Integrity573=== PAUSE TestService_verifyS3Integrity574=== RUN TestCompleteMultipartUnregistered575=== PAUSE TestCompleteMultipartUnregistered576=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT577=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT578=== CONT TestService_AuthMiddleware579=== CONT TestObjectStatsTrigger580=== CONT TestGCTaskStore_DeduplicateSameParams581--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)582=== CONT TestService_createPendingClosureHandler583=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT584=== CONT TestClientErrorHandling585=== CONT TestReadRedirectNar586=== CONT TestService_RequireScope_OIDC587=== CONT TestReadRedirectKeepsNarinfoProxied588=== RUN TestClientErrorHandling/InvalidStorePath589=== PAUSE TestClientErrorHandling/InvalidStorePath590=== RUN TestClientErrorHandling/InvalidAuthToken591=== PAUSE TestClientErrorHandling/InvalidAuthToken592=== RUN TestClientErrorHandling/ServerNotAvailable593=== PAUSE TestClientErrorHandling/ServerNotAvailable594=== CONT TestService_verifyS3Integrity595=== CONT TestGCTaskStore_StartNew596--- PASS: TestGCTaskStore_StartNew (0.00s)597=== CONT TestGCMetrics598=== CONT TestCompleteMultipartUnregistered5992026/09/15 08:18:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56820/oidc6002026-09-15 08:18:06.488 UTC [64233] ERROR: relation "goose_db_version" does not exist at character 366012026-09-15 08:18:06.488 UTC [64233] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6022026-09-15 08:18:06.488 UTC [64232] ERROR: relation "goose_db_version" does not exist at character 366032026-09-15 08:18:06.488 UTC [64232] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6042026-09-15 08:18:06.492 UTC [64234] ERROR: relation "goose_db_version" does not exist at character 366052026-09-15 08:18:06.492 UTC [64234] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6062026-09-15 08:18:06.494 UTC [64236] ERROR: relation "goose_db_version" does not exist at character 366072026-09-15 08:18:06.494 UTC [64236] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6082026-09-15 08:18:06.494 UTC [64238] ERROR: relation "goose_db_version" does not exist at character 366092026-09-15 08:18:06.494 UTC [64238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6102026-09-15 08:18:06.494 UTC [64237] ERROR: relation "goose_db_version" does not exist at character 366112026-09-15 08:18:06.494 UTC [64237] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6122026-09-15 08:18:06.495 UTC [64239] ERROR: relation "goose_db_version" does not exist at character 366132026-09-15 08:18:06.495 UTC [64239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6142026-09-15 08:18:06.496 UTC [64240] ERROR: relation "goose_db_version" does not exist at character 366152026-09-15 08:18:06.496 UTC [64240] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6162026-09-15 08:18:06.496 UTC [64241] ERROR: relation "goose_db_version" does not exist at character 366172026-09-15 08:18:06.496 UTC [64241] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6182026-09-15 08:18:06.497 UTC [64242] ERROR: relation "goose_db_version" does not exist at character 366192026-09-15 08:18:06.497 UTC [64242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6202026/09/15 08:18:06 OK 20241026095416_initial_model.sql (6.41ms)6212026/09/15 08:18:06 OK 20241026095416_initial_model.sql (7.05ms)6222026/09/15 08:18:06 OK 20241026095416_initial_model.sql (4.68ms)6232026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)6242026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)6252026/09/15 08:18:06 OK 20241026095416_initial_model.sql (6.71ms)6262026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)6272026/09/15 08:18:06 OK 20251218171726_add_pins.sql (3.03ms)6282026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)6292026/09/15 08:18:06 OK 20251218171726_add_pins.sql (4.76ms)6302026/09/15 08:18:06 OK 20251218171726_add_pins.sql (3.24ms)6312026/09/15 08:18:06 OK 20241026095416_initial_model.sql (7.95ms)6322026/09/15 08:18:06 OK 20241026095416_initial_model.sql (10.45ms)6332026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)6342026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006352026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)6362026/09/15 08:18:06 OK 20251218171726_add_pins.sql (3.79ms)6372026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (2.23ms)6382026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006392026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)6402026/09/15 08:18:06 OK 20241026095416_initial_model.sql (9.95ms)6412026/09/15 08:18:06 OK 20241026095416_initial_model.sql (7.79ms)6422026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (3.23ms)6432026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006442026/09/15 08:18:06 OK 20241026095416_initial_model.sql (9.97ms)6452026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.35ms)6462026/09/15 08:18:06 OK 20241026095416_initial_model.sql (9.91ms)6472026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)6482026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.64ms)6492026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (1.84ms)6502026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006512026/09/15 08:18:06 OK 20251218171726_add_pins.sql (1.74ms)6522026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)6532026/09/15 08:18:06 OK 2_object_stats_trigger.sql (858.42µs)6542026/09/15 08:18:06 goose: up to current file version: 26552026/09/15 08:18:06 OK 20251218171726_add_pins.sql (2.27ms)6562026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)6572026/09/15 08:18:06 OK 2_object_stats_trigger.sql (742.75µs)6582026/09/15 08:18:06 goose: up to current file version: 26592026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.81ms)6602026/09/15 08:18:06 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)6612026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.63ms)6622026/09/15 08:18:06 OK 2_object_stats_trigger.sql (744.96µs)6632026/09/15 08:18:06 goose: up to current file version: 26642026/09/15 08:18:06 OK 20251218171726_add_pins.sql (2.07ms)6652026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (1.81ms)6662026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006672026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (1.45ms)6682026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006692026/09/15 08:18:06 OK 20251218171726_add_pins.sql (1.81ms)6702026/09/15 08:18:06 OK 20251218171726_add_pins.sql (1.45ms)6712026/09/15 08:18:06 OK 2_object_stats_trigger.sql (541.29µs)6722026/09/15 08:18:06 goose: up to current file version: 26732026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.1ms)6742026/09/15 08:18:06 OK 20251218171726_add_pins.sql (2.05ms)6752026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (1.23ms)6762026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006772026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (1.81ms)6782026/09/15 08:18:06 OK 2_object_stats_trigger.sql (627.17µs)6792026/09/15 08:18:06 goose: up to current file version: 26802026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006812026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (1.72ms)6822026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006832026/09/15 08:18:06 OK 1_commit_pending_closure.sql (2.15ms)6842026/09/15 08:18:06 OK 2_object_stats_trigger.sql (508.17µs)6852026/09/15 08:18:06 goose: up to current file version: 26862026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.53ms)6872026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.15ms)6882026/09/15 08:18:06 OK 2_object_stats_trigger.sql (201.42µs)6892026/09/15 08:18:06 goose: up to current file version: 26902026/09/15 08:18:06 OK 1_commit_pending_closure.sql (1.11ms)6912026/09/15 08:18:06 OK 2_object_stats_trigger.sql (217.54µs)6922026/09/15 08:18:06 goose: up to current file version: 26932026/09/15 08:18:06 OK 2_object_stats_trigger.sql (197.79µs)6942026/09/15 08:18:06 goose: up to current file version: 26952026/09/15 08:18:06 OK 20260628120000_add_object_size_and_stats.sql (8.28ms)6962026/09/15 08:18:06 goose: successfully migrated database to version: 202606281200006972026/09/15 08:18:06 OK 1_commit_pending_closure.sql (12.06ms)6982026/09/15 08:18:06 OK 2_object_stats_trigger.sql (189.71µs)6992026/09/15 08:18:06 goose: up to current file version: 2700--- PASS: TestReadRedirectNar (0.53s)701=== CONT TestGCBugBareHashReferences7022026/09/15 08:18:06 INFO Received uploads request method=POST path=/api/pending_closures7032026/09/15 08:18:06 INFO Received uploads request method=POST path=/api/pending_closures7042026/09/15 08:18:06 INFO Received uploads request method=POST path=/api/pending_closures705--- PASS: TestObjectStatsTrigger (0.85s)706=== CONT TestResolveDBConnectionString707=== RUN TestResolveDBConnectionString/flag_wins708=== PAUSE TestResolveDBConnectionString/flag_wins709=== RUN TestResolveDBConnectionString/file_when_flag_empty710=== PAUSE TestResolveDBConnectionString/file_when_flag_empty711=== RUN TestResolveDBConnectionString/missing_file_is_an_error712=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error713=== RUN TestResolveDBConnectionString/PGHOST_allows_empty714=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty715=== RUN TestResolveDBConnectionString/nothing_configured716=== PAUSE TestResolveDBConnectionString/nothing_configured717=== CONT TestPinProtectsFromGC718--- PASS: TestReadRedirectKeepsNarinfoProxied (0.99s)719=== CONT TestClientWithDependencies7202026/09/15 08:18:07 INFO Aborted multipart uploads count=07212026/09/15 08:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period7222026/09/15 08:18:07 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=07232026/09/15 08:18:07 INFO Vacuumed table table=pending_closures7242026/09/15 08:18:07 INFO Vacuumed table table=pending_objects7252026/09/15 08:18:07 INFO Vacuumed table table=multipart_uploads7262026/09/15 08:18:07 INFO Vacuumed table table=closures7272026/09/15 08:18:07 INFO Vacuumed table table=objects728--- PASS: TestGCMetrics (1.17s)729=== CONT TestClientMultipleUploads7302026-09-15 08:18:07.289 UTC [64387] ERROR: relation "goose_db_version" does not exist at character 367312026-09-15 08:18:07.289 UTC [64387] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026/09/15 08:18:07 OK 20241026095416_initial_model.sql (43.28ms)7332026/09/15 08:18:07 OK 20251210153512_drop_unused_gin_index.sql (12.81ms)7342026/09/15 08:18:07 OK 20251218171726_add_pins.sql (15.43ms)7352026/09/15 08:18:07 OK 20260628120000_add_object_size_and_stats.sql (10.36ms)7362026/09/15 08:18:07 goose: successfully migrated database to version: 202606281200007372026/09/15 08:18:07 OK 1_commit_pending_closure.sql (6.48ms)7382026/09/15 08:18:07 OK 2_object_stats_trigger.sql (262.21µs)7392026/09/15 08:18:07 goose: up to current file version: 2740=== RUN TestService_RequireScope_OIDC/builder_may_write741=== PAUSE TestService_RequireScope_OIDC/builder_may_write742=== RUN TestService_RequireScope_OIDC/builder_may_not_admin743=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin744=== RUN TestService_RequireScope_OIDC/ops_may_admin745=== PAUSE TestService_RequireScope_OIDC/ops_may_admin746=== RUN TestService_RequireScope_OIDC/ops_may_not_write747=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write748=== RUN TestService_RequireScope_OIDC/reader_may_not_write749=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write750=== RUN TestService_RequireScope_OIDC/static_token_may_admin751=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin752=== RUN TestService_RequireScope_OIDC/static_token_may_write753=== PAUSE TestService_RequireScope_OIDC/static_token_may_write754=== RUN TestService_RequireScope_OIDC/reader_may_read755=== PAUSE TestService_RequireScope_OIDC/reader_may_read756=== RUN TestService_RequireScope_OIDC/writer_implies_read757=== PAUSE TestService_RequireScope_OIDC/writer_implies_read758=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read759=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read760=== CONT TestClientIntegration7612026-09-15 08:18:07.526 UTC [64430] ERROR: relation "goose_db_version" does not exist at character 367622026-09-15 08:18:07.526 UTC [64430] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026/09/15 08:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7642026/09/15 08:18:07 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NDU1ZDc2NTAtYmZhMi00MTJlLTg0OGUtM2RjNmMyNGUxMzBkLjcyNjVlZTcxLTk1Y2QtNGMxOS1iNzA1LWIwNDFjY2Q0ZWNiOXgxNzg5NDYwMjg2NzYxODUzMDAw parts=107652026/09/15 08:18:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7662026/09/15 08:18:07 INFO Completed upload id=17672026/09/15 08:18:07 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007682026/09/15 08:18:07 INFO Received uploads request method=POST path=/api/pending_closures7692026/09/15 08:18:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures7702026/09/15 08:18:07 INFO Aborted multipart uploads count=07712026/09/15 08:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7722026/09/15 08:18:07 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst773--- PASS: TestCompleteMultipartUnregistered (1.55s)774=== CONT TestReadProxyDisabled7752026/09/15 08:18:07 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=07762026/09/15 08:18:07 INFO Vacuumed table table=pending_closures7772026/09/15 08:18:07 OK 20241026095416_initial_model.sql (86.42ms)7782026/09/15 08:18:07 INFO Vacuumed table table=pending_objects7792026/09/15 08:18:07 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)7802026/09/15 08:18:07 INFO Vacuumed table table=multipart_uploads7812026/09/15 08:18:07 OK 20251218171726_add_pins.sql (9.11ms)7822026-09-15 08:18:07.655 UTC [64456] ERROR: relation "goose_db_version" does not exist at character 367832026-09-15 08:18:07.655 UTC [64456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026/09/15 08:18:07 INFO Vacuumed table table=closures7852026/09/15 08:18:07 OK 20260628120000_add_object_size_and_stats.sql (14.84ms)7862026/09/15 08:18:07 goose: successfully migrated database to version: 202606281200007872026/09/15 08:18:07 INFO Vacuumed table table=objects7882026/09/15 08:18:07 OK 1_commit_pending_closure.sql (1.93ms)7892026/09/15 08:18:07 OK 2_object_stats_trigger.sql (367.5µs)7902026/09/15 08:18:07 goose: up to current file version: 27912026/09/15 08:18:07 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000792--- PASS: TestService_createPendingClosureHandler (1.59s)793=== CONT TestReadProxyNarinfoAlreadyDecompressed7942026/09/15 08:18:07 OK 20241026095416_initial_model.sql (41.41ms)7952026/09/15 08:18:07 OK 20251210153512_drop_unused_gin_index.sql (7.3ms)7962026/09/15 08:18:07 OK 20251218171726_add_pins.sql (6.52ms)7972026/09/15 08:18:07 OK 20260628120000_add_object_size_and_stats.sql (11.74ms)7982026/09/15 08:18:07 goose: successfully migrated database to version: 202606281200007992026/09/15 08:18:07 OK 1_commit_pending_closure.sql (6.68ms)8002026/09/15 08:18:07 OK 2_object_stats_trigger.sql (249.54µs)8012026/09/15 08:18:07 goose: up to current file version: 28022026-09-15 08:18:07.757 UTC [64471] ERROR: relation "goose_db_version" does not exist at character 368032026-09-15 08:18:07.757 UTC [64471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026/09/15 08:18:07 INFO Received uploads request method=POST path=/api/pending_closures805--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.73s)806=== CONT TestReadProxyNarinfo8072026/09/15 08:18:07 OK 20241026095416_initial_model.sql (51.59ms)8082026/09/15 08:18:07 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)8092026/09/15 08:18:07 OK 20251218171726_add_pins.sql (11.5ms)8102026/09/15 08:18:07 OK 20260628120000_add_object_size_and_stats.sql (10.56ms)8112026/09/15 08:18:07 goose: successfully migrated database to version: 202606281200008122026/09/15 08:18:07 OK 1_commit_pending_closure.sql (1.57ms)8132026/09/15 08:18:07 OK 2_object_stats_trigger.sql (284.79µs)8142026/09/15 08:18:07 goose: up to current file version: 28152026/09/15 08:18:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"816--- PASS: TestService_AuthMiddleware (1.84s)817=== CONT TestReadProxyRootRedirectsToIndexHTML8182026-09-15 08:18:08.002 UTC [64525] ERROR: relation "goose_db_version" does not exist at character 368192026-09-15 08:18:08.002 UTC [64525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026/09/15 08:18:08 INFO Received uploads request method=POST path=/api/pending_closures8212026/09/15 08:18:08 OK 20241026095416_initial_model.sql (60.12ms)8222026/09/15 08:18:08 OK 20251210153512_drop_unused_gin_index.sql (11.07ms)8232026/09/15 08:18:08 OK 20251218171726_add_pins.sql (12.31ms)8242026/09/15 08:18:08 OK 20260628120000_add_object_size_and_stats.sql (19.87ms)8252026/09/15 08:18:08 goose: successfully migrated database to version: 202606281200008262026/09/15 08:18:08 OK 1_commit_pending_closure.sql (1.86ms)8272026/09/15 08:18:08 OK 2_object_stats_trigger.sql (286.21µs)8282026/09/15 08:18:08 goose: up to current file version: 2829--- PASS: TestGCBugBareHashReferences (1.85s)830=== CONT TestIsValidCachePath831=== RUN TestIsValidCachePath/narinfo832=== PAUSE TestIsValidCachePath/narinfo833=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars834=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars835=== RUN TestIsValidCachePath/nar_zst836=== PAUSE TestIsValidCachePath/nar_zst837=== RUN TestIsValidCachePath/nar_xz838=== PAUSE TestIsValidCachePath/nar_xz839=== RUN TestIsValidCachePath/nar_bz2840=== PAUSE TestIsValidCachePath/nar_bz2841=== RUN TestIsValidCachePath/nar_uncompressed842=== PAUSE TestIsValidCachePath/nar_uncompressed843=== RUN TestIsValidCachePath/ls844=== PAUSE TestIsValidCachePath/ls845=== RUN TestIsValidCachePath/log846=== PAUSE TestIsValidCachePath/log847=== RUN TestIsValidCachePath/realisation848=== PAUSE TestIsValidCachePath/realisation849=== RUN TestIsValidCachePath/nix-cache-info850=== PAUSE TestIsValidCachePath/nix-cache-info851=== RUN TestIsValidCachePath/index.html852=== PAUSE TestIsValidCachePath/index.html853=== RUN TestIsValidCachePath/traversal_parent854=== PAUSE TestIsValidCachePath/traversal_parent855=== RUN TestIsValidCachePath/traversal_in_middle856=== PAUSE TestIsValidCachePath/traversal_in_middle857=== RUN TestIsValidCachePath/invalid_char_e858=== PAUSE TestIsValidCachePath/invalid_char_e859=== RUN TestIsValidCachePath/invalid_char_u860=== PAUSE TestIsValidCachePath/invalid_char_u861=== RUN TestIsValidCachePath/random_path862=== PAUSE TestIsValidCachePath/random_path863=== RUN TestIsValidCachePath/empty864=== PAUSE TestIsValidCachePath/empty865=== RUN TestIsValidCachePath/leading_slash866=== PAUSE TestIsValidCachePath/leading_slash867=== RUN TestIsValidCachePath/wrong_extension868=== PAUSE TestIsValidCachePath/wrong_extension869=== RUN TestIsValidCachePath/short_hash870=== PAUSE TestIsValidCachePath/short_hash871=== CONT TestReadProxyConditionalGet8722026-09-15 08:18:08.501 UTC [64618] ERROR: relation "goose_db_version" does not exist at character 368732026-09-15 08:18:08.501 UTC [64618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8742026-09-15 08:18:08.533 UTC [64622] ERROR: relation "goose_db_version" does not exist at character 368752026-09-15 08:18:08.533 UTC [64622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8762026/09/15 08:18:08 OK 20241026095416_initial_model.sql (113.95ms)8772026/09/15 08:18:08 OK 20251210153512_drop_unused_gin_index.sql (5.55ms)8782026/09/15 08:18:08 OK 20241026095416_initial_model.sql (112.81ms)8792026/09/15 08:18:08 OK 20251210153512_drop_unused_gin_index.sql (7.76ms)880=== NAME TestPinProtectsFromGC881 client_integration_test.go:648: Pinned store path: /nix/var/nix/builds/nix-47169-961580207/TestPinProtectsFromGC3248198266/001/store/9pnr4nsks39pqrcbdxnzhkp8w9nsg1l3-pinned-file.txt882 client_integration_test.go:649: Unpinned store path: /nix/var/nix/builds/nix-47169-961580207/TestPinProtectsFromGC3248198266/001/store/jcvfprhpl6xih2ila2lj3wga9lda1m6f-unpinned-file.txt8832026/09/15 08:18:08 OK 20251218171726_add_pins.sql (17.03ms)8842026/09/15 08:18:08 OK 20251218171726_add_pins.sql (40.79ms)8852026/09/15 08:18:08 OK 20260628120000_add_object_size_and_stats.sql (19.71ms)8862026/09/15 08:18:08 goose: successfully migrated database to version: 202606281200008872026/09/15 08:18:08 OK 20260628120000_add_object_size_and_stats.sql (28.89ms)8882026/09/15 08:18:08 goose: successfully migrated database to version: 202606281200008892026/09/15 08:18:08 OK 1_commit_pending_closure.sql (1.2ms)8902026/09/15 08:18:08 OK 2_object_stats_trigger.sql (240.25µs)8912026/09/15 08:18:08 goose: up to current file version: 28922026/09/15 08:18:08 OK 1_commit_pending_closure.sql (4.03ms)8932026/09/15 08:18:08 OK 2_object_stats_trigger.sql (362.17µs)8942026/09/15 08:18:08 goose: up to current file version: 28952026/09/15 08:18:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8962026-09-15 08:18:08.825 UTC [64677] ERROR: relation "goose_db_version" does not exist at character 368972026-09-15 08:18:08.825 UTC [64677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026/09/15 08:18:08 INFO Received uploads request method=POST path=/api/pending_closures8992026/09/15 08:18:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9002026/09/15 08:18:08 INFO Uploading 9pnr4nsks39pqrcbdxnzhkp8w9nsg1l3-pinned-file.txt (128B)9012026/09/15 08:18:08 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9022026/09/15 08:18:08 WARN Failed to register uploaded object key=9pnr4nsks39pqrcbdxnzhkp8w9nsg1l3.ls error="server returned 404: 404 page not found\n"9032026/09/15 08:18:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9042026/09/15 08:18:08 INFO Signed narinfos id=1 count=19052026/09/15 08:18:08 INFO Uploading 1 narinfos9062026/09/15 08:18:08 WARN Failed to register uploaded object key=9pnr4nsks39pqrcbdxnzhkp8w9nsg1l3.narinfo error="server returned 404: 404 page not found\n"9072026/09/15 08:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9082026/09/15 08:18:08 INFO Completed upload id=19092026/09/15 08:18:08 INFO Upload complete. (188ms)9102026-09-15 08:18:08.932 UTC [64706] ERROR: relation "goose_db_version" does not exist at character 369112026-09-15 08:18:08.932 UTC [64706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9122026/09/15 08:18:08 OK 20241026095416_initial_model.sql (61.34ms)9132026/09/15 08:18:08 OK 20251210153512_drop_unused_gin_index.sql (7.17ms)9142026/09/15 08:18:08 OK 20251218171726_add_pins.sql (15.79ms)9152026/09/15 08:18:08 OK 20260628120000_add_object_size_and_stats.sql (33.91ms)9162026/09/15 08:18:08 goose: successfully migrated database to version: 202606281200009172026/09/15 08:18:08 OK 1_commit_pending_closure.sql (4.99ms)9182026/09/15 08:18:08 OK 2_object_stats_trigger.sql (239.63µs)9192026/09/15 08:18:08 goose: up to current file version: 29202026/09/15 08:18:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9212026/09/15 08:18:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete922=== NAME TestClientWithDependencies923 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-47169-961580207/TestClientWithDependencies2077138612/001/store/z15hkh8wa86s9dffjl01hvzglhydzmbw-test-script9242026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures9252026/09/15 08:18:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9262026/09/15 08:18:09 INFO Uploading jcvfprhpl6xih2ila2lj3wga9lda1m6f-unpinned-file.txt (128B)927=== NAME TestClientMultipleUploads928 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-47169-961580207/TestClientMultipleUploads956288945/001/store/kkgj2wvhqvj3pxinvvrbngdda3pf6s3x-test-file-0.txt9292026/09/15 08:18:09 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9302026/09/15 08:18:09 WARN Failed to register uploaded object key=jcvfprhpl6xih2ila2lj3wga9lda1m6f.ls error="server returned 404: 404 page not found\n"9312026/09/15 08:18:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NDU1ZDc2NTAtYmZhMi00MTJlLTg0OGUtM2RjNmMyNGUxMzBkLjFiOGZkZjk0LThkZDMtNDg0MS04Njg4LWEwODY4NTBiOWZiNngxNzg5NDYwMjg4MDgyNzI3MDAw parts=109322026/09/15 08:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9332026/09/15 08:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete934=== NAME TestClientWithDependencies935 client_integration_test.go:596: Found 1 dependencies (including self)9362026/09/15 08:18:09 INFO Signed narinfos id=2 count=19372026/09/15 08:18:09 INFO Uploading 1 narinfos9382026/09/15 08:18:09 OK 20241026095416_initial_model.sql (107.16ms)9392026/09/15 08:18:09 INFO Completed upload id=19402026/09/15 08:18:09 WARN Failed to register uploaded object key=jcvfprhpl6xih2ila2lj3wga9lda1m6f.narinfo error="server returned 404: 404 page not found\n"9412026/09/15 08:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9422026/09/15 08:18:09 INFO Completed upload id=29432026/09/15 08:18:09 INFO Upload complete. (125ms)9442026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures9452026/09/15 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)9462026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/15 08:18:09 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9482026/09/15 08:18:09 WARN Found objects in DB but missing from S3, will re-upload count=1949--- PASS: TestService_verifyS3Integrity (3.00s)950=== CONT TestParseSingleRange951=== RUN TestParseSingleRange/none952=== PAUSE TestParseSingleRange/none953=== RUN TestParseSingleRange/unknown_unit954=== PAUSE TestParseSingleRange/unknown_unit955=== RUN TestParseSingleRange/multi-range_ignored956=== PAUSE TestParseSingleRange/multi-range_ignored957=== RUN TestParseSingleRange/malformed_no_dash958=== PAUSE TestParseSingleRange/malformed_no_dash959=== RUN TestParseSingleRange/malformed_both_empty960=== PAUSE TestParseSingleRange/malformed_both_empty961=== RUN TestParseSingleRange/malformed_end_before_start962=== PAUSE TestParseSingleRange/malformed_end_before_start963=== RUN TestParseSingleRange/closed964=== PAUSE TestParseSingleRange/closed965=== RUN TestParseSingleRange/open-ended966=== PAUSE TestParseSingleRange/open-ended967=== RUN TestParseSingleRange/end_clamped_to_size968=== PAUSE TestParseSingleRange/end_clamped_to_size969=== RUN TestParseSingleRange/suffix970=== PAUSE TestParseSingleRange/suffix971=== RUN TestParseSingleRange/suffix_exceeds_size972=== PAUSE TestParseSingleRange/suffix_exceeds_size973=== RUN TestParseSingleRange/single_byte974=== PAUSE TestParseSingleRange/single_byte975=== RUN TestParseSingleRange/start_past_EOF976=== PAUSE TestParseSingleRange/start_past_EOF977=== RUN TestParseSingleRange/start_far_past_EOF978=== PAUSE TestParseSingleRange/start_far_past_EOF979=== CONT TestReadProxyHead9802026/09/15 08:18:09 OK 20251218171726_add_pins.sql (11.08ms)9812026/09/15 08:18:09 INFO Received create pin request method=POST path=/api/pins/myapp9822026/09/15 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (22.87ms)9832026/09/15 08:18:09 goose: successfully migrated database to version: 202606281200009842026/09/15 08:18:09 OK 1_commit_pending_closure.sql (1.9ms)985=== NAME TestClientMultipleUploads986 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-47169-961580207/TestClientMultipleUploads956288945/001/store/la7ybhp9nri1mxbpaqryplz2pghxycka-test-file-1.txt9872026/09/15 08:18:09 OK 2_object_stats_trigger.sql (335.96µs)9882026/09/15 08:18:09 goose: up to current file version: 29892026/09/15 08:18:09 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-47169-961580207/TestPinProtectsFromGC3248198266/001/store/9pnr4nsks39pqrcbdxnzhkp8w9nsg1l3-pinned-file.txt narinfo_key=9pnr4nsks39pqrcbdxnzhkp8w9nsg1l3.narinfo9902026/09/15 08:18:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures9912026/09/15 08:18:09 INFO Garbage collection started9922026/09/15 08:18:09 INFO Aborted multipart uploads count=09932026/09/15 08:18:09 WARN Force mode enabled - objects will be deleted immediately without grace period9942026/09/15 08:18:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9952026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures9962026/09/15 08:18:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9972026/09/15 08:18:09 INFO Uploading z15hkh8wa86s9dffjl01hvzglhydzmbw-test-script (136B)9982026/09/15 08:18:09 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9992026/09/15 08:18:09 WARN Failed to register uploaded object key=log/zzfgkadi6i97x6gx6rjvfc5jihjhx5bp-test-script.drv error="server returned 404: 404 page not found\n"10002026/09/15 08:18:09 WARN Failed to register uploaded object key=z15hkh8wa86s9dffjl01hvzglhydzmbw.ls error="server returned 404: 404 page not found\n"10012026/09/15 08:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10022026/09/15 08:18:09 INFO Signed narinfos id=1 count=110032026/09/15 08:18:09 INFO Uploading 1 narinfos1004 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-47169-961580207/TestClientMultipleUploads956288945/001/store/nfax0vrnapdc74dpk3vgkgjcp6jmyd1z-test-file-2.txt10052026/09/15 08:18:09 WARN Failed to register uploaded object key=z15hkh8wa86s9dffjl01hvzglhydzmbw.narinfo error="server returned 404: 404 page not found\n"10062026/09/15 08:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10072026/09/15 08:18:09 INFO Completed upload id=110082026/09/15 08:18:09 INFO Upload complete. (92ms)1009=== NAME TestClientWithDependencies1010 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-47169-961580207/TestClientWithDependencies2077138612/001/store) requires matching store prefix1011--- PASS: TestClientWithDependencies (2.13s)1012=== CONT TestReadProxyInvalidPath10132026/09/15 08:18:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1014=== NAME TestClientIntegration1015 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-47169-961580207/TestClientIntegration1646552068/002/store/kj2hwznzr46il6qlxs66is5ms1l11qqk-test-file.txt10162026-09-15 08:18:09.311 UTC [64806] ERROR: relation "goose_db_version" does not exist at character 3610172026-09-15 08:18:09.311 UTC [64806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10182026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures1019--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.64s)1020=== CONT TestResurrectedObjectNotDeleted10212026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures10222026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures10232026/09/15 08:18:09 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10242026/09/15 08:18:09 INFO Uploading nfax0vrnapdc74dpk3vgkgjcp6jmyd1z-test-file-2.txt (160B)10252026/09/15 08:18:09 INFO Uploading la7ybhp9nri1mxbpaqryplz2pghxycka-test-file-1.txt (160B)10262026/09/15 08:18:09 INFO Uploading kkgj2wvhqvj3pxinvvrbngdda3pf6s3x-test-file-0.txt (160B)10272026/09/15 08:18:09 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10282026/09/15 08:18:09 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10292026/09/15 08:18:09 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10302026/09/15 08:18:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10312026/09/15 08:18:09 WARN Failed to register uploaded object key=nfax0vrnapdc74dpk3vgkgjcp6jmyd1z.ls error="server returned 404: 404 page not found\n"10322026/09/15 08:18:09 WARN Failed to register uploaded object key=kkgj2wvhqvj3pxinvvrbngdda3pf6s3x.ls error="server returned 404: 404 page not found\n"10332026/09/15 08:18:09 WARN Failed to register uploaded object key=la7ybhp9nri1mxbpaqryplz2pghxycka.ls error="server returned 404: 404 page not found\n"10342026/09/15 08:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign10352026/09/15 08:18:09 INFO Signed narinfos id=3 count=110362026/09/15 08:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10372026/09/15 08:18:09 INFO Signed narinfos id=1 count=110382026/09/15 08:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10392026/09/15 08:18:09 INFO Signed narinfos id=2 count=110402026/09/15 08:18:09 INFO Uploading 3 narinfos10412026/09/15 08:18:09 WARN Failed to register uploaded object key=kkgj2wvhqvj3pxinvvrbngdda3pf6s3x.narinfo error="server returned 404: 404 page not found\n"10422026/09/15 08:18:09 WARN Failed to register uploaded object key=la7ybhp9nri1mxbpaqryplz2pghxycka.narinfo error="server returned 404: 404 page not found\n"10432026/09/15 08:18:09 WARN Failed to register uploaded object key=nfax0vrnapdc74dpk3vgkgjcp6jmyd1z.narinfo error="server returned 404: 404 page not found\n"10442026/09/15 08:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10452026/09/15 08:18:09 OK 20241026095416_initial_model.sql (42.64ms)10462026/09/15 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (4.81ms)10472026/09/15 08:18:09 OK 20251218171726_add_pins.sql (7.25ms)10482026/09/15 08:18:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=010492026/09/15 08:18:09 INFO Completed upload id=110502026/09/15 08:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10512026/09/15 08:18:09 INFO Completed upload id=210522026/09/15 08:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10532026/09/15 08:18:09 INFO Completed upload id=310542026/09/15 08:18:09 INFO Upload complete. (163ms)1055=== NAME TestClientMultipleUploads1056 client_integration_test.go:350: Uploaded 3 paths in 198.919208ms10572026/09/15 08:18:09 INFO Vacuumed table table=pending_closures10582026/09/15 08:18:09 INFO Received uploads request method=POST path=/api/pending_closures10592026/09/15 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (24.88ms)10602026/09/15 08:18:09 goose: successfully migrated database to version: 2026062812000010612026/09/15 08:18:09 OK 1_commit_pending_closure.sql (1.61ms)10622026/09/15 08:18:09 OK 2_object_stats_trigger.sql (241.83µs)10632026/09/15 08:18:09 goose: up to current file version: 210642026/09/15 08:18:09 INFO Vacuumed table table=pending_objects1065--- PASS: TestClientMultipleUploads (2.16s)1066=== CONT TestReadProxy40410672026/09/15 08:18:09 INFO Vacuumed table table=multipart_uploads10682026/09/15 08:18:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10692026/09/15 08:18:09 INFO Uploading kj2hwznzr46il6qlxs66is5ms1l11qqk-test-file.txt (152B)10702026/09/15 08:18:09 INFO Vacuumed table table=closures10712026/09/15 08:18:09 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10722026/09/15 08:18:09 INFO Vacuumed table table=objects10732026/09/15 08:18:09 WARN Failed to register uploaded object key=kj2hwznzr46il6qlxs66is5ms1l11qqk.ls error="server returned 404: 404 page not found\n"10742026/09/15 08:18:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10752026/09/15 08:18:09 INFO Signed narinfos id=1 count=110762026/09/15 08:18:09 INFO Uploading 1 narinfos10772026/09/15 08:18:09 WARN Failed to register uploaded object key=kj2hwznzr46il6qlxs66is5ms1l11qqk.narinfo error="server returned 404: 404 page not found\n"10782026/09/15 08:18:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10792026/09/15 08:18:09 INFO Completed upload id=110802026/09/15 08:18:09 INFO Upload complete. (164ms)1081=== NAME TestClientIntegration1082 client_integration_test.go:293: Retrieved narinfo from S3:1083 StorePath: /nix/var/nix/builds/nix-47169-961580207/TestClientIntegration1646552068/002/store/kj2hwznzr46il6qlxs66is5ms1l11qqk-test-file.txt1084 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1085 Compression: zstd1086 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11087 NarSize: 1521088 References: 1089 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11090 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1091 client_integration_test.go:294: Decompressed .ls content (64 bytes):1092 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1093 client_integration_test.go:297: Testing garbage collection...1094--- PASS: TestReadProxyDisabled (1.84s)1095=== CONT TestOrphanedObjectsGCStressTest10962026/09/15 08:18:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures10972026/09/15 08:18:09 INFO Garbage collection started10982026/09/15 08:18:09 INFO Aborted multipart uploads count=010992026/09/15 08:18:09 WARN Force mode enabled - objects will be deleted immediately without grace period1100--- PASS: TestReadProxyNarinfo (1.77s)1101=== CONT TestReadProxyNarStreaming11022026/09/15 08:18:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=011032026/09/15 08:18:09 INFO Vacuumed table table=pending_closures11042026/09/15 08:18:09 INFO Vacuumed table table=pending_objects11052026/09/15 08:18:09 INFO Vacuumed table table=multipart_uploads11062026/09/15 08:18:09 INFO Vacuumed table table=closures1107--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.81s)1108=== CONT TestIsValidUploadKey1109=== RUN TestIsValidUploadKey/narinfo1110=== PAUSE TestIsValidUploadKey/narinfo1111=== RUN TestIsValidUploadKey/nar_zst1112=== PAUSE TestIsValidUploadKey/nar_zst1113=== RUN TestIsValidUploadKey/nar_xz1114=== PAUSE TestIsValidUploadKey/nar_xz1115=== RUN TestIsValidUploadKey/nar_plain1116=== PAUSE TestIsValidUploadKey/nar_plain1117=== RUN TestIsValidUploadKey/listing1118=== PAUSE TestIsValidUploadKey/listing1119=== RUN TestIsValidUploadKey/build_log1120=== PAUSE TestIsValidUploadKey/build_log1121=== RUN TestIsValidUploadKey/build_log_home-manager_file1122=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1123=== RUN TestIsValidUploadKey/build_log_plus_in_name1124=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1125=== RUN TestIsValidUploadKey/build_log_question_mark1126=== PAUSE TestIsValidUploadKey/build_log_question_mark1127=== RUN TestIsValidUploadKey/build_log_equals1128=== PAUSE TestIsValidUploadKey/build_log_equals1129=== RUN TestIsValidUploadKey/realisation1130=== PAUSE TestIsValidUploadKey/realisation1131=== RUN TestIsValidUploadKey/realisation_plus_in_output1132=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1133=== RUN TestIsValidUploadKey/nix-cache-info1134=== PAUSE TestIsValidUploadKey/nix-cache-info1135=== RUN TestIsValidUploadKey/index.html1136=== PAUSE TestIsValidUploadKey/index.html1137=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1138=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1139=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1140=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1141=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1142=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1143=== RUN TestIsValidUploadKey/traversal1144=== PAUSE TestIsValidUploadKey/traversal1145=== RUN TestIsValidUploadKey/traversal_nar1146=== PAUSE TestIsValidUploadKey/traversal_nar1147=== RUN TestIsValidUploadKey/absolute1148=== PAUSE TestIsValidUploadKey/absolute1149=== RUN TestIsValidUploadKey/empty_key1150=== PAUSE TestIsValidUploadKey/empty_key1151=== RUN TestIsValidUploadKey/unknown_type1152=== PAUSE TestIsValidUploadKey/unknown_type1153=== CONT TestService_cleanupPendingClosuresHandler11542026/09/15 08:18:09 INFO Vacuumed table table=objects11552026-09-15 08:18:09.759 UTC [64908] ERROR: relation "goose_db_version" does not exist at character 3611562026-09-15 08:18:09.759 UTC [64908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/09/15 08:18:09 OK 20241026095416_initial_model.sql (73.71ms)11582026/09/15 08:18:09 OK 20251210153512_drop_unused_gin_index.sql (8.65ms)11592026/09/15 08:18:09 OK 20251218171726_add_pins.sql (6.71ms)11602026/09/15 08:18:09 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)11612026/09/15 08:18:09 goose: successfully migrated database to version: 202606281200001162--- PASS: TestReadProxyConditionalGet (1.41s)1163=== CONT TestOrphanedObjectsGC11642026-09-15 08:18:09.886 UTC [64937] ERROR: relation "goose_db_version" does not exist at character 3611652026-09-15 08:18:09.886 UTC [64937] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/09/15 08:18:09 OK 1_commit_pending_closure.sql (2.72ms)11672026/09/15 08:18:09 OK 2_object_stats_trigger.sql (815.38µs)11682026/09/15 08:18:09 goose: up to current file version: 211692026/09/15 08:18:10 OK 20241026095416_initial_model.sql (106.85ms)11702026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (7.16ms)11712026/09/15 08:18:10 OK 20251218171726_add_pins.sql (16.18ms)1172--- PASS: TestReadProxyHead (0.96s)1173=== CONT TestUploadHandlersRejectOversizedBody11742026-09-15 08:18:10.053 UTC [64967] ERROR: relation "goose_db_version" does not exist at character 3611752026-09-15 08:18:10.053 UTC [64967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11762026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (8.75ms)11772026/09/15 08:18:10 goose: successfully migrated database to version: 2026062812000011782026/09/15 08:18:10 OK 1_commit_pending_closure.sql (2.73ms)11792026/09/15 08:18:10 OK 2_object_stats_trigger.sql (563.25µs)11802026/09/15 08:18:10 goose: up to current file version: 21181=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1182=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1183=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1184=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1185=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1186=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1187=== CONT TestUploadHandlersRejectInvalidKeys1188=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1189=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1190=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1191=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1192=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1193=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1194=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1195=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1196=== CONT TestCacheStatsHandler11972026/09/15 08:18:10 OK 20241026095416_initial_model.sql (70.7ms)11982026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (7.17ms)11992026-09-15 08:18:10.176 UTC [64988] ERROR: relation "goose_db_version" does not exist at character 3612002026-09-15 08:18:10.176 UTC [64988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12012026/09/15 08:18:10 OK 20251218171726_add_pins.sql (9.26ms)12022026-09-15 08:18:10.177 UTC [64987] ERROR: relation "goose_db_version" does not exist at character 3612032026-09-15 08:18:10.177 UTC [64987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12042026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (19.99ms)12052026/09/15 08:18:10 goose: successfully migrated database to version: 202606281200001206--- PASS: TestReadProxyInvalidPath (0.99s)1207=== CONT TestClientCADerivations12082026/09/15 08:18:10 OK 1_commit_pending_closure.sql (9.54ms)12092026/09/15 08:18:10 OK 2_object_stats_trigger.sql (960.08µs)12102026/09/15 08:18:10 goose: up to current file version: 212112026/09/15 08:18:10 OK 20241026095416_initial_model.sql (41.67ms)12122026/09/15 08:18:10 OK 20241026095416_initial_model.sql (46.22ms)12132026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (4.16ms)12142026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (735.88µs)12152026/09/15 08:18:10 OK 20251218171726_add_pins.sql (10.32ms)12162026/09/15 08:18:10 OK 20251218171726_add_pins.sql (11.11ms)12172026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (7.96ms)12182026/09/15 08:18:10 goose: successfully migrated database to version: 2026062812000012192026/09/15 08:18:10 OK 1_commit_pending_closure.sql (5.94ms)12202026/09/15 08:18:10 OK 2_object_stats_trigger.sql (198.5µs)12212026/09/15 08:18:10 goose: up to current file version: 212222026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (20.88ms)12232026/09/15 08:18:10 goose: successfully migrated database to version: 2026062812000012242026/09/15 08:18:10 OK 1_commit_pending_closure.sql (6.23ms)12252026/09/15 08:18:10 OK 2_object_stats_trigger.sql (225.71µs)12262026/09/15 08:18:10 goose: up to current file version: 21227--- PASS: TestResurrectedObjectNotDeleted (1.07s)1228=== CONT TestCacheConfigHandler1229=== RUN TestCacheConfigHandler/full_config,_no_issuer1230=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1231=== RUN TestCacheConfigHandler/no_cache_url_configured1232=== PAUSE TestCacheConfigHandler/no_cache_url_configured1233=== RUN TestCacheConfigHandler/no_signing_keys1234=== PAUSE TestCacheConfigHandler/no_signing_keys1235=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1236=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1237=== CONT TestService_readinessHandler12382026-09-15 08:18:10.404 UTC [64991] ERROR: relation "goose_db_version" does not exist at character 3612392026-09-15 08:18:10.404 UTC [64991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026-09-15 08:18:10.507 UTC [64994] ERROR: relation "goose_db_version" does not exist at character 3612412026-09-15 08:18:10.507 UTC [64994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12422026/09/15 08:18:10 OK 20241026095416_initial_model.sql (82.28ms)12432026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (7.43ms)12442026/09/15 08:18:10 OK 20251218171726_add_pins.sql (6.22ms)12452026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (23.59ms)12462026/09/15 08:18:10 goose: successfully migrated database to version: 2026062812000012472026/09/15 08:18:10 OK 1_commit_pending_closure.sql (6.68ms)12482026/09/15 08:18:10 OK 2_object_stats_trigger.sql (239.88µs)12492026/09/15 08:18:10 goose: up to current file version: 212502026/09/15 08:18:10 OK 20241026095416_initial_model.sql (77.06ms)12512026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (5.69ms)12522026/09/15 08:18:10 OK 20251218171726_add_pins.sql (22.46ms)1253--- PASS: TestReadProxy404 (1.24s)1254=== CONT TestMetricsInventory12552026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (16.59ms)12562026/09/15 08:18:10 goose: successfully migrated database to version: 2026062812000012572026-09-15 08:18:10.676 UTC [64998] ERROR: relation "goose_db_version" does not exist at character 3612582026-09-15 08:18:10.676 UTC [64998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12592026/09/15 08:18:10 OK 1_commit_pending_closure.sql (1.76ms)12602026/09/15 08:18:10 OK 2_object_stats_trigger.sql (207.21µs)12612026/09/15 08:18:10 goose: up to current file version: 212622026/09/15 08:18:10 OK 20241026095416_initial_model.sql (63.9ms)12632026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (8.42ms)12642026/09/15 08:18:10 OK 20251218171726_add_pins.sql (15.37ms)1265--- PASS: TestReadProxyNarStreaming (1.20s)1266=== CONT TestNARDeduplicationMetadataUploadBug12672026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (18.4ms)12682026/09/15 08:18:10 goose: successfully migrated database to version: 2026062812000012692026/09/15 08:18:10 OK 1_commit_pending_closure.sql (5.37ms)12702026/09/15 08:18:10 OK 2_object_stats_trigger.sql (270.46µs)12712026/09/15 08:18:10 goose: up to current file version: 212722026-09-15 08:18:10.846 UTC [65065] ERROR: relation "goose_db_version" does not exist at character 3612732026-09-15 08:18:10.846 UTC [65065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12742026/09/15 08:18:10 INFO Received cleanup request method=DELETE path=/api/pending_closures12752026-09-15 08:18:10.949 UTC [65073] ERROR: relation "goose_db_version" does not exist at character 3612762026-09-15 08:18:10.949 UTC [65073] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026/09/15 08:18:10 INFO Aborted multipart uploads count=012782026/09/15 08:18:10 INFO Received uploads request method=POST path=/api/pending_closures12792026/09/15 08:18:10 OK 20241026095416_initial_model.sql (80.11ms)12802026/09/15 08:18:10 OK 20251210153512_drop_unused_gin_index.sql (6.85ms)12812026/09/15 08:18:10 INFO Received cleanup request method=DELETE path=/api/pending_closures12822026/09/15 08:18:10 OK 20251218171726_add_pins.sql (26.18ms)12832026/09/15 08:18:10 INFO Aborted multipart uploads count=112842026/09/15 08:18:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12852026-09-15 08:18:10.995 UTC [64994] ERROR: Closure does not exist: id=112862026-09-15 08:18:10.995 UTC [64994] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12872026-09-15 08:18:10.995 UTC [64994] STATEMENT: -- name: CommitPendingClosure :exec1288 SELECT commit_pending_closure($1::bigint)1289 1290--- PASS: TestService_cleanupPendingClosuresHandler (1.25s)1291=== CONT TestMultipartCleanup12922026/09/15 08:18:10 OK 20260628120000_add_object_size_and_stats.sql (9.38ms)12932026/09/15 08:18:10 goose: successfully migrated database to version: 2026062812000012942026/09/15 08:18:10 OK 1_commit_pending_closure.sql (2.71ms)12952026/09/15 08:18:10 OK 2_object_stats_trigger.sql (305.46µs)12962026/09/15 08:18:10 goose: up to current file version: 212972026/09/15 08:18:11 OK 20241026095416_initial_model.sql (55.47ms)12982026/09/15 08:18:11 OK 20251210153512_drop_unused_gin_index.sql (7.74ms)12992026/09/15 08:18:11 OK 20251218171726_add_pins.sql (8.99ms)13002026/09/15 08:18:11 OK 20260628120000_add_object_size_and_stats.sql (15.43ms)13012026/09/15 08:18:11 goose: successfully migrated database to version: 2026062812000013022026/09/15 08:18:11 OK 1_commit_pending_closure.sql (1.85ms)13032026/09/15 08:18:11 OK 2_object_stats_trigger.sql (258.79µs)13042026/09/15 08:18:11 goose: up to current file version: 213052026/09/15 08:18:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01306=== NAME TestPinProtectsFromGC1307 client_integration_test.go:711: Pin successfully protected closure from garbage collection1308--- PASS: TestPinProtectsFromGC (4.23s)1309=== CONT TestServerTLSConfig1310=== RUN TestServerTLSConfig/no_client_CA1311=== PAUSE TestServerTLSConfig/no_client_CA1312=== RUN TestServerTLSConfig/missing_CA_file1313=== PAUSE TestServerTLSConfig/missing_CA_file1314=== RUN TestServerTLSConfig/not_a_PEM_file1315=== PAUSE TestServerTLSConfig/not_a_PEM_file1316=== CONT TestCreatePendingClosureRejectsOversizedNAR13172026/09/15 08:18:11 INFO Received uploads request method=POST path=/api/pending_closures1318--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1319=== CONT TestService_NativeMTLS13202026-09-15 08:18:11.227 UTC [65078] ERROR: relation "goose_db_version" does not exist at character 3613212026-09-15 08:18:11.227 UTC [65078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1322--- PASS: TestCacheStatsHandler (1.24s)1323=== CONT TestCacheConfigHandlerMaxNarSize1324--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1325=== CONT TestGenerateLandingPage1326--- PASS: TestGenerateLandingPage (0.00s)1327=== CONT TestService_ReadAuthMiddleware13282026/09/15 08:18:11 OK 20241026095416_initial_model.sql (64.39ms)13292026/09/15 08:18:11 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)13302026/09/15 08:18:11 OK 20251218171726_add_pins.sql (13.63ms)13312026/09/15 08:18:11 OK 20260628120000_add_object_size_and_stats.sql (15ms)13322026/09/15 08:18:11 goose: successfully migrated database to version: 2026062812000013332026/09/15 08:18:11 OK 1_commit_pending_closure.sql (2.13ms)13342026/09/15 08:18:11 OK 2_object_stats_trigger.sql (372.13µs)13352026/09/15 08:18:11 goose: up to current file version: 213362026-09-15 08:18:11.489 UTC [65081] ERROR: relation "goose_db_version" does not exist at character 3613372026-09-15 08:18:11.489 UTC [65081] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13382026/09/15 08:18:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01339=== NAME TestClientIntegration1340 client_integration_test.go:304: Objects in database after GC:1341 client_integration_test.go:304: Successfully deleted all objects with GC --force1342--- PASS: TestClientIntegration (4.08s)1343=== CONT TestService_AuthMiddleware_OIDC13442026/09/15 08:18:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56949/oidc13452026/09/15 08:18:11 OK 20241026095416_initial_model.sql (69.2ms)1346=== NAME TestOrphanedObjectsGC1347 orphaned_objects_gc_test.go:290: GC Test Summary:1348 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1349 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1350 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1351 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1352 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1353--- PASS: TestOrphanedObjectsGC (1.70s)1354=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13552026/09/15 08:18:11 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)13562026/09/15 08:18:11 OK 20251218171726_add_pins.sql (9.5ms)13572026/09/15 08:18:11 OK 20260628120000_add_object_size_and_stats.sql (28.6ms)13582026/09/15 08:18:11 goose: successfully migrated database to version: 2026062812000013592026/09/15 08:18:11 OK 1_commit_pending_closure.sql (2.45ms)13602026/09/15 08:18:11 OK 2_object_stats_trigger.sql (789.67µs)13612026/09/15 08:18:11 goose: up to current file version: 213622026-09-15 08:18:11.660 UTC [65091] ERROR: relation "goose_db_version" does not exist at character 3613632026-09-15 08:18:11.660 UTC [65091] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13642026/09/15 08:18:11 WARN readiness check failed error="closed pool"1365--- PASS: TestService_readinessHandler (1.27s)1366=== CONT TestService_AuthMiddleware_MTLSProxyHeader13672026/09/15 08:18:11 OK 20241026095416_initial_model.sql (57.06ms)13682026/09/15 08:18:11 OK 20251210153512_drop_unused_gin_index.sql (7.07ms)13692026/09/15 08:18:11 OK 20251218171726_add_pins.sql (12.3ms)1370=== NAME TestClientCADerivations1371 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-47169-961580207/TestClientCADerivations3094371161/001/store/hxb51zamp1hwb15xs7xkxf6dhzl75b7k-ca-test13722026/09/15 08:18:11 OK 20260628120000_add_object_size_and_stats.sql (17.48ms)13732026/09/15 08:18:11 goose: successfully migrated database to version: 2026062812000013742026-09-15 08:18:11.771 UTC [65094] ERROR: relation "goose_db_version" does not exist at character 3613752026-09-15 08:18:11.771 UTC [65094] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13762026/09/15 08:18:11 OK 1_commit_pending_closure.sql (17.75ms)13772026/09/15 08:18:11 OK 2_object_stats_trigger.sql (459.63µs)13782026/09/15 08:18:11 goose: up to current file version: 21379 client_ca_test.go:139: Found 1 dependencies (including self)13802026/09/15 08:18:11 OK 20241026095416_initial_model.sql (78.15ms)13812026/09/15 08:18:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1382--- PASS: TestMetricsInventory (1.23s)1383=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13842026/09/15 08:18:11 OK 20251210153512_drop_unused_gin_index.sql (8.91ms)13852026/09/15 08:18:11 OK 20251218171726_add_pins.sql (7.09ms)13862026/09/15 08:18:11 OK 20260628120000_add_object_size_and_stats.sql (11.92ms)13872026/09/15 08:18:11 goose: successfully migrated database to version: 2026062812000013882026/09/15 08:18:11 OK 1_commit_pending_closure.sql (2.08ms)13892026/09/15 08:18:11 OK 2_object_stats_trigger.sql (251.88µs)13902026/09/15 08:18:11 goose: up to current file version: 213912026/09/15 08:18:11 INFO Received uploads request method=POST path=/api/pending_closures13922026/09/15 08:18:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/09/15 08:18:11 INFO Uploading hxb51zamp1hwb15xs7xkxf6dhzl75b7k-ca-test (144B)13942026/09/15 08:18:11 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13952026/09/15 08:18:11 WARN Failed to register uploaded object key=log/f5qn015cbfwd6rd1gs9n0h01ixr5mysh-ca-test.drv error="server returned 404: 404 page not found\n"13962026/09/15 08:18:11 WARN Failed to register uploaded object key=hxb51zamp1hwb15xs7xkxf6dhzl75b7k.ls error="server returned 404: 404 page not found\n"13972026/09/15 08:18:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13982026/09/15 08:18:11 INFO Signed narinfos id=1 count=113992026/09/15 08:18:11 INFO Uploading 1 narinfos14002026/09/15 08:18:11 WARN Failed to register uploaded object key=hxb51zamp1hwb15xs7xkxf6dhzl75b7k.narinfo error="server returned 404: 404 page not found\n"14012026/09/15 08:18:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14022026/09/15 08:18:12 INFO Completed upload id=114032026/09/15 08:18:12 INFO Upload complete. (175ms)1404=== NAME TestClientCADerivations1405 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-47169-961580207/TestClientCADerivations3094371161/001/store/hxb51zamp1hwb15xs7xkxf6dhzl75b7k-ca-test1406 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1407 Compression: zstd1408 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1409 NarSize: 1441410 References: 1411 Deriver: /nix/var/nix/builds/nix-47169-961580207/TestClientCADerivations3094371161/001/store/f5qn015cbfwd6rd1gs9n0h01ixr5mysh-ca-test.drv1412 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1413 client_ca_test.go:185: Checking for realisation files in S3...1414 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1415 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1416 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket31?endpoint=http://localhost:56775®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-47169-961580207/TestClientCADerivations3094371161/001/store'1417 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114182026-09-15 08:18:12.164 UTC [65107] ERROR: relation "goose_db_version" does not exist at character 3614192026-09-15 08:18:12.164 UTC [65107] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1420--- PASS: TestClientCADerivations (2.01s)1421=== CONT TestPresignedUploadRegisteredBeforeCommit1422=== NAME TestNARDeduplicationMetadataUploadBug1423 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-47169-961580207/TestNARDeduplicationMetadataUploadBug2746832074/001/store/wh59806j7iyy4h692aqrh25gvpicqknc-file1.txt14242026/09/15 08:18:12 OK 20241026095416_initial_model.sql (87.59ms)14252026/09/15 08:18:12 OK 20251210153512_drop_unused_gin_index.sql (9.85ms)14262026/09/15 08:18:12 OK 20251218171726_add_pins.sql (29.11ms)14272026/09/15 08:18:12 INFO Received uploads request method=POST path=/api/pending_closures14282026/09/15 08:18:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14292026/09/15 08:18:12 OK 20260628120000_add_object_size_and_stats.sql (28.77ms)14302026/09/15 08:18:12 goose: successfully migrated database to version: 2026062812000014312026/09/15 08:18:12 OK 1_commit_pending_closure.sql (8.83ms)14322026/09/15 08:18:12 OK 2_object_stats_trigger.sql (254.63µs)14332026/09/15 08:18:12 goose: up to current file version: 214342026/09/15 08:18:12 INFO Received uploads request method=POST path=/api/pending_closures14352026/09/15 08:18:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14362026/09/15 08:18:12 INFO Uploading wh59806j7iyy4h692aqrh25gvpicqknc-file1.txt (160B)14372026-09-15 08:18:12.475 UTC [65118] ERROR: relation "goose_db_version" does not exist at character 3614382026-09-15 08:18:12.475 UTC [65118] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026/09/15 08:18:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14402026/09/15 08:18:12 WARN Failed to register uploaded object key=wh59806j7iyy4h692aqrh25gvpicqknc.ls error="server returned 404: 404 page not found\n"14412026/09/15 08:18:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14422026/09/15 08:18:12 INFO Signed narinfos id=1 count=114432026/09/15 08:18:12 INFO Uploading 1 narinfos14442026/09/15 08:18:12 WARN Failed to register uploaded object key=wh59806j7iyy4h692aqrh25gvpicqknc.narinfo error="server returned 404: 404 page not found\n"14452026/09/15 08:18:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14462026/09/15 08:18:12 INFO Received cleanup request method=DELETE path=/api/pending_closures14472026/09/15 08:18:12 INFO Aborted multipart uploads count=114482026/09/15 08:18:12 INFO Completed upload id=114492026/09/15 08:18:12 INFO Upload complete. (234ms)1450 metadata_upload_test.go:54: Retrieved narinfo from S3:1451 StorePath: /nix/var/nix/builds/nix-47169-961580207/TestNARDeduplicationMetadataUploadBug2746832074/001/store/wh59806j7iyy4h692aqrh25gvpicqknc-file1.txt1452 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1453 Compression: zstd1454 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1455 NarSize: 1601456 References: 1457 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1458 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1459 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1460 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1461--- PASS: TestMultipartCleanup (1.55s)1462=== CONT TestCompletedNarNotReofferedAcrossClosures1463=== NAME TestNARDeduplicationMetadataUploadBug1464 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-47169-961580207/TestNARDeduplicationMetadataUploadBug2746832074/001/store/bwa5yq8qjsamwnjjb4062l3x1nmil0hi-file2.txt14652026/09/15 08:18:12 OK 20241026095416_initial_model.sql (128.79ms)14662026/09/15 08:18:12 OK 20251210153512_drop_unused_gin_index.sql (13.64ms)14672026/09/15 08:18:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14682026/09/15 08:18:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1469--- PASS: TestService_NativeMTLS (1.50s)1470=== CONT TestService_Rustfstest14712026/09/15 08:18:12 OK 20251218171726_add_pins.sql (9.14ms)14722026/09/15 08:18:12 OK 20260628120000_add_object_size_and_stats.sql (16.99ms)14732026/09/15 08:18:12 goose: successfully migrated database to version: 2026062812000014742026-09-15 08:18:12.698 UTC [65128] ERROR: relation "goose_db_version" does not exist at character 3614752026-09-15 08:18:12.698 UTC [65128] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14762026/09/15 08:18:12 OK 1_commit_pending_closure.sql (1.45ms)14772026/09/15 08:18:12 OK 2_object_stats_trigger.sql (220.25µs)14782026/09/15 08:18:12 goose: up to current file version: 214792026/09/15 08:18:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14802026/09/15 08:18:12 INFO Received uploads request method=POST path=/api/pending_closures14812026/09/15 08:18:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14822026/09/15 08:18:12 WARN Failed to register uploaded object key=bwa5yq8qjsamwnjjb4062l3x1nmil0hi.ls error="server returned 404: 404 page not found\n"14832026/09/15 08:18:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14842026/09/15 08:18:12 INFO Signed narinfos id=2 count=114852026/09/15 08:18:12 INFO Uploading 1 narinfos14862026/09/15 08:18:12 WARN Failed to register uploaded object key=bwa5yq8qjsamwnjjb4062l3x1nmil0hi.narinfo error="server returned 404: 404 page not found\n"14872026/09/15 08:18:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14882026/09/15 08:18:12 INFO Completed upload id=214892026/09/15 08:18:12 INFO Upload complete. (138ms)1490=== NAME TestNARDeduplicationMetadataUploadBug1491 metadata_upload_test.go:76: Retrieved narinfo from S3:1492 StorePath: /nix/var/nix/builds/nix-47169-961580207/TestNARDeduplicationMetadataUploadBug2746832074/001/store/bwa5yq8qjsamwnjjb4062l3x1nmil0hi-file2.txt1493 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1494 Compression: zstd1495 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1496 NarSize: 1601497 References: 1498 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1499 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1500 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1501 {"version":1,"root":{"type":"regular","size":44}}15022026-09-15 08:18:12.877 UTC [65132] ERROR: relation "goose_db_version" does not exist at character 3615032026-09-15 08:18:12.877 UTC [65132] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1504--- PASS: TestNARDeduplicationMetadataUploadBug (2.09s)1505=== CONT TestService_ReadScope_PublicByDefault15062026/09/15 08:18:12 OK 20241026095416_initial_model.sql (114.78ms)15072026/09/15 08:18:12 OK 20251210153512_drop_unused_gin_index.sql (9.74ms)15082026/09/15 08:18:12 OK 20251218171726_add_pins.sql (20.7ms)15092026/09/15 08:18:12 OK 20260628120000_add_object_size_and_stats.sql (45.15ms)15102026/09/15 08:18:12 goose: successfully migrated database to version: 2026062812000015112026/09/15 08:18:12 OK 1_commit_pending_closure.sql (6.56ms)15122026/09/15 08:18:12 OK 2_object_stats_trigger.sql (267.38µs)15132026/09/15 08:18:12 goose: up to current file version: 21514--- PASS: TestService_ReadAuthMiddleware (1.67s)1515=== CONT TestGCTaskStore_PhaseUpdates1516--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1517=== CONT TestGracefulShutdownDrainsInflight15182026/09/15 08:18:12 INFO Starting HTTP server address=127.0.0.1:5697215192026/09/15 08:18:12 INFO Shutdown signal received, draining in-flight requests timeout=10s15202026-09-15 08:18:13.035 UTC [65142] ERROR: relation "goose_db_version" does not exist at character 3615212026-09-15 08:18:13.035 UTC [65142] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1522--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1523=== CONT TestGCTaskStore_Fail1524--- PASS: TestGCTaskStore_Fail (0.00s)1525=== CONT TestService_healthCheckHandler15262026/09/15 08:18:13 OK 20241026095416_initial_model.sql (155.86ms)15272026/09/15 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (8.24ms)15282026/09/15 08:18:13 OK 20251218171726_add_pins.sql (35.24ms)15292026/09/15 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (17.94ms)15302026/09/15 08:18:13 goose: successfully migrated database to version: 2026062812000015312026/09/15 08:18:13 OK 1_commit_pending_closure.sql (8.21ms)15322026/09/15 08:18:13 OK 2_object_stats_trigger.sql (841.63µs)15332026/09/15 08:18:13 goose: up to current file version: 215342026/09/15 08:18:13 OK 20241026095416_initial_model.sql (135.87ms)15352026/09/15 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (15.4ms)1536=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1537=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1538=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1539=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1540=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1541=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1542=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1543=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1544=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15452026/09/15 08:18:13 OK 20251218171726_add_pins.sql (27.74ms)15462026/09/15 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (35.45ms)15472026/09/15 08:18:13 goose: successfully migrated database to version: 2026062812000015482026/09/15 08:18:13 OK 1_commit_pending_closure.sql (8.28ms)15492026/09/15 08:18:13 OK 2_object_stats_trigger.sql (600.54µs)15502026/09/15 08:18:13 goose: up to current file version: 215512026/09/15 08:18:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15522026/09/15 08:18:13 WARN mTLS auth: bound subjects configured but subject DN unavailable15532026/09/15 08:18:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1554--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.00s)1555=== CONT TestProxyWriteTimeout15562026-09-15 08:18:13.581 UTC [65148] ERROR: relation "goose_db_version" does not exist at character 3615572026-09-15 08:18:13.581 UTC [65148] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1558=== RUN TestProxyWriteTimeout/narinfo1559=== PAUSE TestProxyWriteTimeout/narinfo1560=== RUN TestProxyWriteTimeout/1_GiB_nar1561=== PAUSE TestProxyWriteTimeout/1_GiB_nar1562=== RUN TestProxyWriteTimeout/10_GiB_nar1563=== PAUSE TestProxyWriteTimeout/10_GiB_nar1564=== RUN TestProxyWriteTimeout/unknown_size1565=== PAUSE TestProxyWriteTimeout/unknown_size1566=== CONT TestSkippedUploadsHandler15672026/09/15 08:18:13 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001568--- PASS: TestSkippedUploadsHandler (0.00s)1569=== CONT TestGCTaskStore_CompletedAllowsNewTask1570--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1571=== CONT TestGCTaskStore_GetReturnsLatest1572--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1573=== CONT TestReadRedirectUsesPublicS3URL15742026/09/15 08:18:13 OK 20241026095416_initial_model.sql (57.92ms)15752026/09/15 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (8.66ms)15762026/09/15 08:18:13 OK 20251218171726_add_pins.sql (17.94ms)15772026/09/15 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (19.44ms)15782026/09/15 08:18:13 goose: successfully migrated database to version: 2026062812000015792026/09/15 08:18:13 OK 1_commit_pending_closure.sql (9.77ms)15802026/09/15 08:18:13 OK 2_object_stats_trigger.sql (950.38µs)15812026/09/15 08:18:13 goose: up to current file version: 215822026-09-15 08:18:13.785 UTC [65153] ERROR: relation "goose_db_version" does not exist at character 3615832026-09-15 08:18:13.785 UTC [65153] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1584--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.15s)1585=== CONT TestReadProxyRangeRequest15862026/09/15 08:18:13 OK 20241026095416_initial_model.sql (78.62ms)15872026/09/15 08:18:13 OK 20251210153512_drop_unused_gin_index.sql (6.59ms)15882026-09-15 08:18:13.906 UTC [65156] ERROR: relation "goose_db_version" does not exist at character 3615892026-09-15 08:18:13.906 UTC [65156] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15902026/09/15 08:18:13 OK 20251218171726_add_pins.sql (15.76ms)15912026/09/15 08:18:13 OK 20260628120000_add_object_size_and_stats.sql (20.99ms)15922026/09/15 08:18:13 goose: successfully migrated database to version: 2026062812000015932026/09/15 08:18:13 OK 1_commit_pending_closure.sql (10.13ms)15942026/09/15 08:18:13 OK 2_object_stats_trigger.sql (1.09ms)15952026/09/15 08:18:13 goose: up to current file version: 215962026/09/15 08:18:14 INFO Received uploads request method=POST path=/api/pending_closures15972026/09/15 08:18:14 OK 20241026095416_initial_model.sql (85.58ms)15982026/09/15 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (11.56ms)15992026-09-15 08:18:14.069 UTC [65157] ERROR: relation "goose_db_version" does not exist at character 3616002026-09-15 08:18:14.069 UTC [65157] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16012026/09/15 08:18:14 OK 20251218171726_add_pins.sql (23.28ms)16022026/09/15 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (23.09ms)16032026/09/15 08:18:14 goose: successfully migrated database to version: 2026062812000016042026/09/15 08:18:14 OK 1_commit_pending_closure.sql (3.07ms)16052026/09/15 08:18:14 OK 2_object_stats_trigger.sql (762.83µs)16062026/09/15 08:18:14 goose: up to current file version: 216072026/09/15 08:18:14 OK 20241026095416_initial_model.sql (121.37ms)16082026/09/15 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (15.31ms)16092026/09/15 08:18:14 OK 20251218171726_add_pins.sql (34.21ms)16102026/09/15 08:18:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16112026/09/15 08:18:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDU1ZDc2NTAtYmZhMi00MTJlLTg0OGUtM2RjNmMyNGUxMzBkLmRiNGQxYjcyLWFlZmUtNDNmZi05MWNhLTJiYTMyZTQ0M2YzZHgxNzg5NDYwMjk0MDU2NjU0MDAw16122026/09/15 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (31.46ms)16132026/09/15 08:18:14 goose: successfully migrated database to version: 2026062812000016142026/09/15 08:18:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDU1ZDc2NTAtYmZhMi00MTJlLTg0OGUtM2RjNmMyNGUxMzBkLmRiNGQxYjcyLWFlZmUtNDNmZi05MWNhLTJiYTMyZTQ0M2YzZHgxNzg5NDYwMjk0MDU2NjU0MDAw parts=11615--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.42s)1616=== CONT TestRedundantMultipartUpload16172026/09/15 08:18:14 OK 1_commit_pending_closure.sql (5.35ms)16182026/09/15 08:18:14 OK 2_object_stats_trigger.sql (705.54µs)16192026/09/15 08:18:14 goose: up to current file version: 216202026/09/15 08:18:14 INFO Received uploads request method=POST path=/api/pending_closures16212026-09-15 08:18:14.374 UTC [65161] ERROR: relation "goose_db_version" does not exist at character 3616222026-09-15 08:18:14.374 UTC [65161] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16232026/09/15 08:18:14 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16242026/09/15 08:18:14 INFO Received uploads request method=POST path=/api/pending_closures1625--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.17s)1626=== CONT TestGCTaskStore_GetEmpty1627--- PASS: TestGCTaskStore_GetEmpty (0.00s)1628=== CONT TestGCTaskStore_ConflictDifferentParams1629--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1630=== CONT TestClientErrorHandling/InvalidStorePath16312026-09-15 08:18:14.427 UTC [65171] ERROR: relation "goose_db_version" does not exist at character 3616322026-09-15 08:18:14.427 UTC [65171] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16332026/09/15 08:18:14 OK 20241026095416_initial_model.sql (67.88ms)16342026/09/15 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (3.33ms)16352026-09-15 08:18:14.476 UTC [65194] ERROR: relation "goose_db_version" does not exist at character 3616362026-09-15 08:18:14.476 UTC [65194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16372026/09/15 08:18:14 OK 20251218171726_add_pins.sql (4.21ms)16382026/09/15 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (22.69ms)16392026/09/15 08:18:14 goose: successfully migrated database to version: 2026062812000016402026/09/15 08:18:14 OK 1_commit_pending_closure.sql (3.2ms)16412026/09/15 08:18:14 OK 2_object_stats_trigger.sql (267.29µs)16422026/09/15 08:18:14 goose: up to current file version: 216432026/09/15 08:18:14 OK 20241026095416_initial_model.sql (45.67ms)16442026/09/15 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (11.23ms)16452026/09/15 08:18:14 OK 20251218171726_add_pins.sql (10.38ms)16462026/09/15 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (22.62ms)16472026/09/15 08:18:14 goose: successfully migrated database to version: 2026062812000016482026/09/15 08:18:14 OK 1_commit_pending_closure.sql (8.15ms)16492026/09/15 08:18:14 OK 2_object_stats_trigger.sql (237.71µs)16502026/09/15 08:18:14 goose: up to current file version: 216512026/09/15 08:18:14 INFO Received uploads request method=POST path=/api/pending_closures16522026/09/15 08:18:14 OK 20241026095416_initial_model.sql (94.46ms)16532026/09/15 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (8.72ms)1654=== NAME TestOrphanedObjectsGCStressTest1655 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16562026/09/15 08:18:14 OK 20251218171726_add_pins.sql (18.55ms)16572026/09/15 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (19.21ms)16582026/09/15 08:18:14 goose: successfully migrated database to version: 2026062812000016592026/09/15 08:18:14 OK 1_commit_pending_closure.sql (6.11ms)16602026/09/15 08:18:14 OK 2_object_stats_trigger.sql (307.83µs)16612026/09/15 08:18:14 goose: up to current file version: 21662 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16632026-09-15 08:18:14.660 UTC [65210] ERROR: relation "goose_db_version" does not exist at character 3616642026-09-15 08:18:14.660 UTC [65210] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16652026/09/15 08:18:14 OK 20241026095416_initial_model.sql (114.07ms)16662026/09/15 08:18:14 OK 20251210153512_drop_unused_gin_index.sql (7.97ms)1667--- PASS: TestService_Rustfstest (2.16s)1668=== CONT TestClientErrorHandling/ServerNotAvailable16692026/09/15 08:18:14 OK 20251218171726_add_pins.sql (20.62ms)16702026/09/15 08:18:14 OK 20260628120000_add_object_size_and_stats.sql (57.25ms)16712026/09/15 08:18:14 goose: successfully migrated database to version: 2026062812000016722026/09/15 08:18:14 OK 1_commit_pending_closure.sql (6.52ms)16732026/09/15 08:18:14 OK 2_object_stats_trigger.sql (268.08µs)16742026/09/15 08:18:14 goose: up to current file version: 216752026-09-15 08:18:15.054 UTC [65314] ERROR: relation "goose_db_version" does not exist at character 3616762026-09-15 08:18:15.054 UTC [65314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16772026/09/15 08:18:15 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-config1678--- PASS: TestService_ReadScope_PublicByDefault (2.26s)1679=== CONT TestClientErrorHandling/InvalidAuthToken16802026/09/15 08:18:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.015022ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16812026/09/15 08:18:15 OK 20241026095416_initial_model.sql (172.06ms)16822026/09/15 08:18:15 OK 20251210153512_drop_unused_gin_index.sql (16.57ms)16832026/09/15 08:18:15 OK 20251218171726_add_pins.sql (33.55ms)16842026/09/15 08:18:15 OK 20260628120000_add_object_size_and_stats.sql (36.21ms)16852026/09/15 08:18:15 goose: successfully migrated database to version: 2026062812000016862026/09/15 08:18:15 OK 1_commit_pending_closure.sql (1.62ms)16872026/09/15 08:18:15 OK 2_object_stats_trigger.sql (247.29µs)16882026/09/15 08:18:15 goose: up to current file version: 21689--- PASS: TestService_healthCheckHandler (2.35s)1690=== CONT TestParseSize1691--- PASS: TestParseSize (0.00s)1692=== CONT TestResolveDBConnectionString/flag_wins1693=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1694=== CONT TestResolveDBConnectionString/nothing_configured1695=== CONT TestResolveDBConnectionString/missing_file_is_an_error1696=== CONT TestResolveDBConnectionString/file_when_flag_empty1697=== CONT TestService_RequireScope_OIDC/builder_may_write16982026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[write]1699=== CONT TestService_RequireScope_OIDC/static_token_may_admin1700=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1701=== CONT TestService_RequireScope_OIDC/writer_implies_read17022026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[write]1703=== CONT TestService_RequireScope_OIDC/reader_may_read17042026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[read]1705=== CONT TestService_RequireScope_OIDC/static_token_may_write1706=== CONT TestService_RequireScope_OIDC/ops_may_not_write17072026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[admin]1708=== CONT TestService_RequireScope_OIDC/reader_may_not_write17092026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[read]1710=== CONT TestService_RequireScope_OIDC/ops_may_admin17112026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[admin]1712=== CONT TestService_RequireScope_OIDC/builder_may_not_admin17132026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[write]1714=== CONT TestIsValidCachePath/narinfo1715=== CONT TestIsValidCachePath/index.html1716=== CONT TestIsValidCachePath/short_hash1717=== CONT TestIsValidCachePath/wrong_extension1718=== CONT TestIsValidCachePath/leading_slash1719=== CONT TestIsValidCachePath/empty1720=== CONT TestIsValidCachePath/random_path1721=== CONT TestIsValidCachePath/invalid_char_u1722=== CONT TestIsValidCachePath/invalid_char_e1723=== CONT TestIsValidCachePath/traversal_in_middle1724=== CONT TestIsValidCachePath/traversal_parent1725=== CONT TestIsValidCachePath/nar_uncompressed1726=== CONT TestIsValidCachePath/nix-cache-info1727=== CONT TestIsValidCachePath/nar_xz1728=== CONT TestIsValidCachePath/nar_bz21729=== CONT TestIsValidCachePath/realisation1730=== CONT TestIsValidCachePath/log1731=== CONT TestIsValidCachePath/ls1732=== CONT TestIsValidCachePath/nar_zst1733=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1734--- PASS: TestIsValidCachePath (0.00s)1735 --- PASS: TestIsValidCachePath/narinfo (0.00s)1736 --- PASS: TestIsValidCachePath/index.html (0.00s)1737 --- PASS: TestIsValidCachePath/short_hash (0.00s)1738 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1739 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1740 --- PASS: TestIsValidCachePath/empty (0.00s)1741 --- PASS: TestIsValidCachePath/random_path (0.00s)1742 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1743 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1744 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1745 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1746 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1747 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1748 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1749 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1750 --- PASS: TestIsValidCachePath/realisation (0.00s)1751 --- PASS: TestIsValidCachePath/log (0.00s)1752 --- PASS: TestIsValidCachePath/ls (0.00s)1753 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1754 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1755=== CONT TestParseSingleRange/none1756=== CONT TestParseSingleRange/open-ended1757=== CONT TestParseSingleRange/start_far_past_EOF1758=== CONT TestParseSingleRange/start_past_EOF1759=== CONT TestParseSingleRange/single_byte1760=== CONT TestParseSingleRange/suffix_exceeds_size1761=== CONT TestParseSingleRange/suffix1762=== CONT TestParseSingleRange/end_clamped_to_size1763=== CONT TestParseSingleRange/malformed_both_empty1764=== CONT TestParseSingleRange/closed1765=== CONT TestParseSingleRange/malformed_end_before_start1766=== CONT TestParseSingleRange/multi-range_ignored1767=== CONT TestParseSingleRange/malformed_no_dash1768=== CONT TestParseSingleRange/unknown_unit1769--- PASS: TestParseSingleRange (0.00s)1770 --- PASS: TestParseSingleRange/none (0.00s)1771 --- PASS: TestParseSingleRange/open-ended (0.00s)1772 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1773 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1774 --- PASS: TestParseSingleRange/single_byte (0.00s)1775 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1776 --- PASS: TestParseSingleRange/suffix (0.00s)1777 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1778 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1779 --- PASS: TestParseSingleRange/closed (0.00s)1780 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1781 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1782 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1783 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1784=== CONT TestIsValidUploadKey/narinfo1785=== CONT TestIsValidUploadKey/realisation_plus_in_output1786=== CONT TestIsValidUploadKey/unknown_type1787=== CONT TestIsValidUploadKey/empty_key1788=== CONT TestIsValidUploadKey/absolute1789=== CONT TestIsValidUploadKey/traversal_nar1790=== CONT TestIsValidUploadKey/traversal1791=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1792=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1793=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1794=== CONT TestIsValidUploadKey/index.html1795=== CONT TestIsValidUploadKey/nix-cache-info1796=== CONT TestIsValidUploadKey/build_log_home-manager_file1797=== CONT TestIsValidUploadKey/realisation1798=== CONT TestIsValidUploadKey/build_log_equals1799=== CONT TestIsValidUploadKey/build_log_question_mark1800=== CONT TestIsValidUploadKey/build_log_plus_in_name1801=== CONT TestIsValidUploadKey/nar_plain1802=== CONT TestIsValidUploadKey/build_log1803=== CONT TestIsValidUploadKey/listing1804=== CONT TestIsValidUploadKey/nar_zst1805=== CONT TestIsValidUploadKey/nar_xz1806--- PASS: TestIsValidUploadKey (0.00s)1807 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1808 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1809 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1810 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1811 --- PASS: TestIsValidUploadKey/absolute (0.00s)1812 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1813 --- PASS: TestIsValidUploadKey/traversal (0.00s)1814 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1815 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1816 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1817 --- PASS: TestIsValidUploadKey/index.html (0.00s)1818 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1819 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1820 --- PASS: TestIsValidUploadKey/realisation (0.00s)1821 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1822 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1823 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1824 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1825 --- PASS: TestIsValidUploadKey/build_log (0.00s)1826 --- PASS: TestIsValidUploadKey/listing (0.00s)1827 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1828 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1829=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18302026/09/15 08:18:15 INFO Received uploads request method=POST path=/1831--- PASS: TestService_RequireScope_OIDC (1.37s)1832 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1835 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1836 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1842--- PASS: TestResolveDBConnectionString (0.02s)1843 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1844 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1845 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1846 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1847 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18482026/09/15 08:18:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.36001ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1849=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18502026/09/15 08:18:15 INFO Received request for more parts method=POST path=/18512026/09/15 08:18:15 INFO Received uploads request method=POST path=/api/pending_closures1852=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18532026/09/15 08:18:15 INFO Received complete multipart upload request method=POST path=/1854--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1855 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1856 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1857 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1858=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18592026/09/15 08:18:15 INFO Received uploads request method=POST path=/1860=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18612026/09/15 08:18:15 INFO Received complete multipart upload request method=POST path=/1862=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18632026/09/15 08:18:15 INFO Received request for more parts method=POST path=/1864=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18652026/09/15 08:18:15 INFO Received uploads request method=POST path=/1866--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1867 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1868 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1869 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1870 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1871=== CONT TestCacheConfigHandler/full_config,_no_issuer1872=== CONT TestCacheConfigHandler/no_signing_keys1873=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1874=== CONT TestCacheConfigHandler/no_cache_url_configured1875--- PASS: TestCacheConfigHandler (0.00s)1876 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1877 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1878 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1879 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1880=== CONT TestServerTLSConfig/no_client_CA1881=== CONT TestServerTLSConfig/not_a_PEM_file1882=== CONT TestServerTLSConfig/missing_CA_file1883--- PASS: TestServerTLSConfig (0.00s)1884 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1885 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1886 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1887=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token18882026/09/15 08:18:15 INFO OIDC auth successful provider=test scopes=[write]1889=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18902026/09/15 08:18:15 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1891=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1892=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18932026/09/15 08:18:15 WARN Authentication failed token_preview=eyJhbGciOi...ZKr5vlYFXA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1894=== CONT TestProxyWriteTimeout/narinfo1895=== CONT TestProxyWriteTimeout/10_GiB_nar1896=== CONT TestProxyWriteTimeout/unknown_size1897=== CONT TestProxyWriteTimeout/1_GiB_nar1898--- PASS: TestProxyWriteTimeout (0.00s)1899 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1900 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1901 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1902 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1903--- PASS: TestService_AuthMiddleware_OIDC (1.74s)1904 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1905 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1906 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1907 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19082026-09-15 08:18:15.843 UTC [65680] ERROR: relation "goose_db_version" does not exist at character 3619092026-09-15 08:18:15.843 UTC [65680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19102026/09/15 08:18:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=838.167479ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19112026-09-15 08:18:15.981 UTC [65758] ERROR: relation "goose_db_version" does not exist at character 3619122026-09-15 08:18:15.981 UTC [65758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19132026/09/15 08:18:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1914--- PASS: TestReadRedirectUsesPublicS3URL (2.47s)19152026/09/15 08:18:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19162026/09/15 08:18:16 OK 20241026095416_initial_model.sql (132.58ms)19172026/09/15 08:18:16 OK 20251210153512_drop_unused_gin_index.sql (7.65ms)19182026/09/15 08:18:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NDU1ZDc2NTAtYmZhMi00MTJlLTg0OGUtM2RjNmMyNGUxMzBkLjVlODAzMjczLTJlZWYtNDYwZi1hNTg2LWI1ZGI1OTNiNDQxNXgxNzg5NDYwMjk0NTkwODQ3MDAw parts=1219192026/09/15 08:18:16 INFO Received uploads request method=POST path=/api/pending_closures1920--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.55s)19212026/09/15 08:18:16 OK 20251218171726_add_pins.sql (37.81ms)19222026/09/15 08:18:16 OK 20260628120000_add_object_size_and_stats.sql (25.23ms)19232026/09/15 08:18:16 goose: successfully migrated database to version: 2026062812000019242026/09/15 08:18:16 OK 1_commit_pending_closure.sql (5.8ms)19252026/09/15 08:18:16 OK 2_object_stats_trigger.sql (367.21µs)19262026/09/15 08:18:16 goose: up to current file version: 219272026/09/15 08:18:16 OK 20241026095416_initial_model.sql (122.26ms)19282026/09/15 08:18:16 OK 20251210153512_drop_unused_gin_index.sql (4.92ms)19292026/09/15 08:18:16 OK 20251218171726_add_pins.sql (8.29ms)19302026/09/15 08:18:16 OK 20260628120000_add_object_size_and_stats.sql (17.36ms)19312026/09/15 08:18:16 goose: successfully migrated database to version: 2026062812000019322026/09/15 08:18:16 OK 1_commit_pending_closure.sql (1.77ms)19332026/09/15 08:18:16 OK 2_object_stats_trigger.sql (686.96µs)19342026/09/15 08:18:16 goose: up to current file version: 21935--- PASS: TestReadProxyRangeRequest (2.46s)19362026-09-15 08:18:16.422 UTC [66157] ERROR: relation "goose_db_version" does not exist at character 3619372026-09-15 08:18:16.422 UTC [66157] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19382026/09/15 08:18:16 INFO Received uploads request method=POST path=/api/pending_closures19392026/09/15 08:18:16 INFO Received uploads request method=POST path=/api/pending_closures19402026/09/15 08:18:16 OK 20241026095416_initial_model.sql (118.92ms)19412026/09/15 08:18:16 OK 20251210153512_drop_unused_gin_index.sql (13.46ms)19422026/09/15 08:18:16 OK 20251218171726_add_pins.sql (14.98ms)19432026/09/15 08:18:16 OK 20260628120000_add_object_size_and_stats.sql (26.88ms)19442026/09/15 08:18:16 goose: successfully migrated database to version: 2026062812000019452026/09/15 08:18:16 OK 1_commit_pending_closure.sql (11.81ms)19462026/09/15 08:18:16 OK 2_object_stats_trigger.sql (688.29µs)19472026/09/15 08:18:16 goose: up to current file version: 219482026/09/15 08:18:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.583487576s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19492026/09/15 08:18:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19502026/09/15 08:18:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1951=== NAME TestOrphanedObjectsGCStressTest1952 orphaned_objects_gc_test.go:509: Stress test completed successfully:1953 orphaned_objects_gc_test.go:510: - Active objects preserved: 201954 orphaned_objects_gc_test.go:511: - Objects deleted: 2101955 orphaned_objects_gc_test.go:512: - Total GC'd: 2101956--- PASS: TestOrphanedObjectsGCStressTest (7.76s)19572026/09/15 08:18:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19582026/09/15 08:18:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDU1ZDc2NTAtYmZhMi00MTJlLTg0OGUtM2RjNmMyNGUxMzBkLmJmNGY5MTliLTBhODgtNDYxMi04N2YwLWY5ZGRkYzY0NGFkY3gxNzg5NDYwMjk2NDk4ODM2MDAw parts=121959--- PASS: TestRedundantMultipartUpload (3.27s)19602026/09/15 08:18:18 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"19612026/09/15 08:18:18 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_closures19622026/09/15 08:18:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.775932ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19632026/09/15 08:18:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.83347ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19642026/09/15 08:18:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=754.035218ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19652026/09/15 08:18:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.668240497s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19662026/09/15 08:18:20 WARN Rate limiter enabled after throttle name=s3-test rate=519672026/09/15 08:18:20 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1968=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1969 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101970 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001971--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.53s)1972--- PASS: TestClientErrorHandling (0.00s)1973 --- PASS: TestClientErrorHandling/InvalidStorePath (2.42s)1974 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.11s)1975 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.64s)1976PASS1977{"timestamp":"2026-09-15T08:18:21.477809Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56870","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1866,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}19782026-09-15 08:18:21.567 UTC [63092] LOG: received smart shutdown request19792026-09-15 08:18:21.568 UTC [63092] LOG: background worker "logical replication launcher" (PID 63107) exited with exit code 119802026-09-15 08:18:21.588 UTC [63102] LOG: shutting down19812026-09-15 08:18:21.588 UTC [63102] LOG: checkpoint starting: shutdown immediate19822026-09-15 08:18:22.696 UTC [63102] LOG: checkpoint complete: wrote 13495 buffers (82.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 15 recycled; write=0.768 s, sync=0.311 s, total=1.108 s; sync files=17141, longest=0.001 s, average=0.001 s; distance=240171 kB, estimate=240171 kB; lsn=0/10217E20, redo lsn=0/10217E2019832026-09-15 08:18:22.709 UTC [63092] LOG: database system is shut down1984Running OIDC tests...1985=== RUN TestGlobMatch1986=== PAUSE TestGlobMatch1987=== RUN TestAudienceForIssuer1988=== PAUSE TestAudienceForIssuer1989=== RUN TestValidateToken_ValidToken1990=== PAUSE TestValidateToken_ValidToken1991=== RUN TestValidateToken_WrongAudience1992=== PAUSE TestValidateToken_WrongAudience1993=== RUN TestValidateToken_Expired1994=== PAUSE TestValidateToken_Expired1995=== RUN TestValidateToken_BoundClaimsMismatch1996=== PAUSE TestValidateToken_BoundClaimsMismatch1997=== RUN TestValidateToken_BoundSubjectMismatch1998=== PAUSE TestValidateToken_BoundSubjectMismatch1999=== RUN TestValidateToken_MultipleProviders2000=== PAUSE TestValidateToken_MultipleProviders2001=== RUN TestValidateToken_NoMatchingProvider2002=== PAUSE TestValidateToken_NoMatchingProvider2003=== RUN TestValidateToken_KubernetesServiceAccount2004=== PAUSE TestValidateToken_KubernetesServiceAccount2005=== RUN TestNewValidator_KubernetesRequiresCA2006=== PAUSE TestNewValidator_KubernetesRequiresCA2007=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2008=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2009=== RUN TestScopes_LegacyProviderDefaultsToWrite2010=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2011=== RUN TestScopes_Rules2012=== PAUSE TestScopes_Rules2013=== RUN TestScopes_ConfigValidation2014=== PAUSE TestScopes_ConfigValidation2015=== CONT TestGlobMatch2016=== RUN TestGlobMatch/foo_foo2017=== CONT TestValidateToken_NoMatchingProvider2018=== PAUSE TestGlobMatch/foo_foo2019=== RUN TestGlobMatch/foo_bar2020=== PAUSE TestGlobMatch/foo_bar2021=== RUN TestGlobMatch/*_2022=== PAUSE TestGlobMatch/*_2023=== RUN TestGlobMatch/*_anything2024=== PAUSE TestGlobMatch/*_anything2025=== RUN TestGlobMatch/foo*_foo2026=== PAUSE TestGlobMatch/foo*_foo2027=== RUN TestGlobMatch/foo*_foobar2028=== PAUSE TestGlobMatch/foo*_foobar2029=== RUN TestGlobMatch/foo*_bar2030=== PAUSE TestGlobMatch/foo*_bar2031=== RUN TestGlobMatch/*bar_bar2032=== PAUSE TestGlobMatch/*bar_bar2033=== RUN TestGlobMatch/*bar_foobar2034=== PAUSE TestGlobMatch/*bar_foobar2035=== RUN TestGlobMatch/*bar_foo2036=== PAUSE TestGlobMatch/*bar_foo2037=== RUN TestGlobMatch/foo*bar_foobar2038=== PAUSE TestGlobMatch/foo*bar_foobar2039=== RUN TestGlobMatch/foo*bar_foo123bar2040=== PAUSE TestGlobMatch/foo*bar_foo123bar2041=== RUN TestGlobMatch/foo*bar_foobarbaz2042=== PAUSE TestGlobMatch/foo*bar_foobarbaz2043=== RUN TestGlobMatch/*/*_foo/bar2044=== PAUSE TestGlobMatch/*/*_foo/bar2045=== CONT TestValidateToken_MultipleProviders2046=== RUN TestGlobMatch/*/*_foo2047=== PAUSE TestGlobMatch/*/*_foo2048=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2049=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2050=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02051=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02052=== RUN TestGlobMatch/refs/*/main_refs/heads/main2053=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2054=== RUN TestGlobMatch/fo?_foo2055=== PAUSE TestGlobMatch/fo?_foo2056=== RUN TestGlobMatch/fo?_fo2057=== PAUSE TestGlobMatch/fo?_fo2058=== RUN TestGlobMatch/fo?_fooo2059=== PAUSE TestGlobMatch/fo?_fooo2060=== RUN TestGlobMatch/?oo_foo2061=== PAUSE TestGlobMatch/?oo_foo2062=== RUN TestGlobMatch/?oo_boo2063=== PAUSE TestGlobMatch/?oo_boo2064=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2065=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2066=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2067=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2068=== CONT TestScopes_ConfigValidation2069=== CONT TestValidateToken_BoundSubjectMismatch2070=== CONT TestValidateToken_BoundClaimsMismatch2071=== CONT TestValidateToken_Expired2072=== CONT TestValidateToken_WrongAudience2073=== CONT TestValidateToken_ValidToken2074=== CONT TestAudienceForIssuer2075--- PASS: TestAudienceForIssuer (0.00s)2076=== CONT TestScopes_Rules2077=== CONT TestScopes_LegacyProviderDefaultsToWrite20782026/09/15 08:18:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57055/oidc20792026/09/15 08:18:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57056/oidc20802026/09/15 08:18:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57057/oidc2081--- PASS: TestScopes_ConfigValidation (0.00s)2082=== CONT TestNewValidator_KubernetesRequiresCA20832026/09/15 08:18:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57061/oidc20842026/09/15 08:18:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57058/oidc20852026/09/15 08:18:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57070/oidc20862026/09/15 08:18:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57067/oidc20872026/09/15 08:18:23 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:57059/oidc2088--- PASS: TestValidateToken_Expired (0.01s)2089=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2090--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2091=== CONT TestValidateToken_KubernetesServiceAccount2092--- PASS: TestValidateToken_ValidToken (0.01s)2093=== CONT TestGlobMatch/foo_foo2094=== CONT TestGlobMatch/*bar_bar2095=== CONT TestGlobMatch/foo*bar_foobarbaz2096=== CONT TestGlobMatch/foo*bar_foo123bar2097=== CONT TestGlobMatch/foo*bar_foobar2098=== CONT TestGlobMatch/*bar_foo2099=== CONT TestGlobMatch/*bar_foobar2100=== CONT TestGlobMatch/foo*_foo2101=== CONT TestGlobMatch/foo*_bar2102=== CONT TestGlobMatch/foo*_foobar2103=== CONT TestGlobMatch/*_2104=== CONT TestGlobMatch/*_anything2105=== CONT TestGlobMatch/fo?_fo2106=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2107=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2108=== CONT TestGlobMatch/?oo_boo2109=== CONT TestGlobMatch/?oo_foo2110=== CONT TestGlobMatch/fo?_fooo2111=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02112=== CONT TestGlobMatch/fo?_foo21132026/09/15 08:18:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57071/oidc2114=== CONT TestGlobMatch/refs/*/main_refs/heads/main2115=== CONT TestGlobMatch/foo_bar2116=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2117=== CONT TestGlobMatch/*/*_foo2118=== CONT TestGlobMatch/*/*_foo/bar2119--- PASS: TestGlobMatch (0.00s)2120 --- PASS: TestGlobMatch/foo_foo (0.00s)2121 --- PASS: TestGlobMatch/*bar_bar (0.00s)2122 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2123 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2124 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2125 --- PASS: TestGlobMatch/*bar_foo (0.00s)2126 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2127 --- PASS: TestGlobMatch/foo*_foo (0.00s)2128 --- PASS: TestGlobMatch/foo*_bar (0.00s)2129 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2130 --- PASS: TestGlobMatch/*_ (0.00s)2131 --- PASS: TestGlobMatch/*_anything (0.00s)2132 --- PASS: TestGlobMatch/fo?_fo (0.00s)2133 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2134 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s2026/09/15 08:18:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57073/oidc2135)2136 --- PASS: TestGlobMatch/?oo_boo (0.00s)2137 --- PASS: TestGlobMatch/?oo_foo (0.00s)2138 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2139 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2140 --- PASS: TestGlobMatch/fo?_foo (0.00s)2141 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2142 --- PASS: TestGlobMatch/foo_bar (0.00s)2143 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2144 --- PASS: TestGlobMatch/*/*_foo (0.00s)2145 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2146--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2147--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2148--- PASS: TestValidateToken_WrongAudience (0.01s)2149--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2150--- PASS: TestValidateToken_MultipleProviders (0.01s)21512026/09/15 08:18:23 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5707821522026/09/15 08:18:23 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232153--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)21542026/09/15 08:18:23 http: TLS handshake error from 127.0.0.1:57077: remote error: tls: bad certificate2155--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2156--- PASS: TestScopes_Rules (0.02s)2157--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2158PASS2159Running hook tests...2160=== RUN TestSendPathsEmpty2161=== PAUSE TestSendPathsEmpty2162=== RUN TestQueueEnqueueAndFetch2163=== PAUSE TestQueueEnqueueAndFetch2164=== RUN TestQueueDeduplication2165=== PAUSE TestQueueDeduplication2166=== RUN TestQueueRemove2167=== PAUSE TestQueueRemove2168=== RUN TestQueueFetchBatchLimit2169=== PAUSE TestQueueFetchBatchLimit2170=== RUN TestQueueRetryMovesToBack2171=== PAUSE TestQueueRetryMovesToBack2172=== RUN TestQueueFetchRemoveLifecycle2173=== PAUSE TestQueueFetchRemoveLifecycle2174=== RUN TestQueueConcurrentWriters2175=== PAUSE TestQueueConcurrentWriters2176=== RUN TestQueueRemoveLargeClosure2177=== PAUSE TestQueueRemoveLargeClosure2178=== RUN TestServerClientIntegration2179=== PAUSE TestServerClientIntegration2180=== RUN TestServerQueueError2181=== PAUSE TestServerQueueError2182=== RUN TestGetListenerSocketActivation2183 server_test.go:210: === RUN TestGetListenerSocketActivation2184 --- PASS: TestGetListenerSocketActivation (0.00s)2185 PASS2186 2187--- PASS: TestGetListenerSocketActivation (0.01s)2188=== RUN TestDrainIsolatesPoisonPath2189=== PAUSE TestDrainIsolatesPoisonPath2190=== RUN TestRunNotBlockedByPoisonHead2191=== PAUSE TestRunNotBlockedByPoisonHead2192=== RUN TestDrainGivesUpWhenServerDown2193=== PAUSE TestDrainGivesUpWhenServerDown2194=== RUN TestFailedPathPrunedByLaterClosure2195=== PAUSE TestFailedPathPrunedByLaterClosure2196=== RUN TestWorkerUploadsAndRemoves2197=== PAUSE TestWorkerUploadsAndRemoves2198=== RUN TestWorkerSkipsGCdPaths2199=== PAUSE TestWorkerSkipsGCdPaths2200=== RUN TestWorkerPrunesClosureDeps2201=== PAUSE TestWorkerPrunesClosureDeps2202=== RUN TestDrainTimeout2203=== PAUSE TestDrainTimeout2204=== CONT TestSendPathsEmpty2205=== CONT TestServerQueueError2206--- PASS: TestSendPathsEmpty (0.00s)2207=== CONT TestQueueFetchBatchLimit2208=== CONT TestWorkerUploadsAndRemoves2209=== CONT TestQueueRetryMovesToBack2210=== CONT TestQueueRemove2211=== CONT TestQueueDeduplication2212=== CONT TestQueueEnqueueAndFetch2213=== CONT TestQueueRemoveLargeClosure2214=== CONT TestServerClientIntegration2215=== CONT TestDrainGivesUpWhenServerDown22162026/09/15 08:18:24 ERROR Failed to queue paths error="permission denied" count=12217--- PASS: TestServerQueueError (0.00s)2218=== CONT TestFailedPathPrunedByLaterClosure2219--- PASS: TestServerClientIntegration (0.00s)2220=== CONT TestQueueConcurrentWriters22212026/09/15 08:18:24 INFO Upload queue status pending=22222--- PASS: TestQueueFetchBatchLimit (0.01s)2223=== CONT TestQueueFetchRemoveLifecycle22242026/09/15 08:18:24 INFO Uploading batch count=122252026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=122262026/09/15 08:18:24 INFO Uploading batch count=222272026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=222282026/09/15 08:18:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-47169-961580207/TestDrainGivesUpWhenServerDown2598963714/002/a2229--- PASS: TestQueueEnqueueAndFetch (0.01s)2230=== CONT TestWorkerPrunesClosureDeps22312026/09/15 08:18:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-47169-961580207/TestDrainGivesUpWhenServerDown2598963714/002/b22322026/09/15 08:18:24 INFO Uploading batch count=222332026/09/15 08:18:24 INFO Uploading batch count=222342026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=222352026/09/15 08:18:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-47169-961580207/TestDrainGivesUpWhenServerDown2598963714/002/c2236--- PASS: TestQueueRemove (0.01s)2237=== CONT TestDrainTimeout2238--- PASS: TestQueueRetryMovesToBack (0.01s)2239=== CONT TestWorkerSkipsGCdPaths22402026/09/15 08:18:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-47169-961580207/TestDrainGivesUpWhenServerDown2598963714/002/d2241--- PASS: TestQueueDeduplication (0.01s)22422026/09/15 08:18:24 INFO Uploading batch count=22243=== CONT TestRunNotBlockedByPoisonHead22442026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=222452026/09/15 08:18:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-47169-961580207/TestDrainGivesUpWhenServerDown2598963714/002/e22462026/09/15 08:18:24 INFO Uploading batch count=122472026/09/15 08:18:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-47169-961580207/TestDrainGivesUpWhenServerDown2598963714/002/f22482026/09/15 08:18:24 ERROR Drain finished with paths left in queue remaining=1022492026/09/15 08:18:24 INFO Uploading batch count=12250--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2251=== CONT TestDrainIsolatesPoisonPath2252--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2253--- PASS: TestDrainGivesUpWhenServerDown (0.01s)22542026/09/15 08:18:24 INFO Upload queue status pending=222552026/09/15 08:18:24 INFO Uploading batch count=122562026/09/15 08:18:24 INFO Upload queue status pending=322572026/09/15 08:18:24 INFO Upload queue status pending=222582026/09/15 08:18:24 INFO Uploading batch count=222592026/09/15 08:18:24 INFO Uploading batch count=122602026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=122612026/09/15 08:18:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-47169-961580207/TestWorkerSkipsGCdPaths3358583808/002/nonexistent22622026/09/15 08:18:24 INFO Uploading batch count=422632026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=422642026/09/15 08:18:24 INFO Uploading batch count=122652026/09/15 08:18:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-47169-961580207/TestDrainIsolatesPoisonPath2482107330/002/bbb22662026/09/15 08:18:24 INFO Uploading batch count=122672026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=122682026/09/15 08:18:24 INFO Uploading batch count=122692026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=122702026/09/15 08:18:24 INFO Uploading batch count=122712026/09/15 08:18:24 ERROR Upload failed error="upload failed" count=122722026/09/15 08:18:24 ERROR Drain finished with paths left in queue remaining=12273--- PASS: TestDrainIsolatesPoisonPath (0.00s)2274--- PASS: TestWorkerUploadsAndRemoves (0.03s)2275--- PASS: TestWorkerPrunesClosureDeps (0.02s)2276--- PASS: TestWorkerSkipsGCdPaths (0.02s)2277--- PASS: TestQueueRemoveLargeClosure (0.05s)2278--- PASS: TestQueueConcurrentWriters (0.15s)22792026/09/15 08:18:24 ERROR Upload failed error="context deadline exceeded" count=222802026/09/15 08:18:24 ERROR Drain finished with paths left in queue remaining=42281--- PASS: TestDrainTimeout (0.21s)22822026/09/15 08:18:25 INFO Uploading batch count=122832026/09/15 08:18:25 INFO Uploading batch count=122842026/09/15 08:18:25 INFO Uploading batch count=122852026/09/15 08:18:25 ERROR Upload failed error="upload failed" count=122862026/09/15 08:18:25 INFO Uploading batch count=122872026/09/15 08:18:25 ERROR Upload failed error="upload failed" count=122882026/09/15 08:18:25 INFO Uploading batch count=122892026/09/15 08:18:25 ERROR Upload failed error="upload failed" count=122902026/09/15 08:18:25 INFO Uploading batch count=122912026/09/15 08:18:25 ERROR Upload failed error="upload failed" count=122922026/09/15 08:18:25 ERROR Drain finished with paths left in queue remaining=12293--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2294PASS