niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #240
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestSetClientTLS65=== PAUSE TestSetClientTLS66=== RUN TestSetClientTLSDoesNotMutateDefaultTransport67=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport68=== RUN TestSetClientTLSErrors69=== PAUSE TestSetClientTLSErrors70=== RUN TestStaticToken71=== PAUSE TestStaticToken72=== RUN TestFileTokenReadsAndCaches73=== PAUSE TestFileTokenReadsAndCaches74=== RUN TestFileTokenMissing75=== PAUSE TestFileTokenMissing76=== RUN TestFileTokenEmpty77=== PAUSE TestFileTokenEmpty78=== RUN TestScriptTokenNoExpiryRerunsEveryCall79=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall80=== RUN TestScriptTokenCachesUntilRefresh81=== PAUSE TestScriptTokenCachesUntilRefresh82=== RUN TestScriptTokenEmptyToken83=== PAUSE TestScriptTokenEmptyToken84=== RUN TestScriptTokenBadJSON85=== PAUSE TestScriptTokenBadJSON86=== RUN TestScriptTokenScriptFails87=== PAUSE TestScriptTokenScriptFails88=== RUN TestScriptTokenEmptyCommand89=== PAUSE TestScriptTokenEmptyCommand90=== CONT TestDoServerRequestAttachesToken91=== CONT TestDoWithRetry_BodyReplayedViaGetBody92=== CONT TestEncodeNixBase32WithRealHash93--- PASS: TestEncodeNixBase32WithRealHash (0.00s)94=== CONT TestGetStorePathHash95=== RUN TestGetStorePathHash/valid_store_path96=== PAUSE TestGetStorePathHash/valid_store_path97=== RUN TestGetStorePathHash/basename_without_hyphen_should_error98=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error99=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error100=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error101=== CONT TestResolveStorePath102=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess103=== CONT TestRateLimiterFeedback104=== RUN TestRateLimiterFeedback/429_enables_limiter105=== PAUSE TestRateLimiterFeedback/429_enables_limiter106=== RUN TestRateLimiterFeedback/503_enables_limiter1072026/09/21 18:17:13 WARN Rate limiter enabled after throttle name=server-test rate=5108=== PAUSE TestRateLimiterFeedback/503_enables_limiter109=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter110=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter111=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter112=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter113=== CONT TestConvertHashToNix32114=== RUN TestConvertHashToNix32/SRI_format_to_Nix32115=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32116=== RUN TestConvertHashToNix32/already_Nix32_format117=== PAUSE TestConvertHashToNix32/already_Nix32_format118=== RUN TestConvertHashToNix32/invalid_format119=== PAUSE TestConvertHashToNix32/invalid_format120=== CONT TestUploadMultipart_SupersededByPeer121=== RUN TestUploadMultipart_SupersededByPeer/exists122=== PAUSE TestUploadMultipart_SupersededByPeer/exists123=== RUN TestUploadMultipart_SupersededByPeer/missing124=== PAUSE TestUploadMultipart_SupersededByPeer/missing125=== CONT TestEncodeNixBase32126=== RUN TestEncodeNixBase32/test_string_hash127=== PAUSE TestEncodeNixBase32/test_string_hash128=== CONT TestPathInfoCACompatibility129=== RUN TestPathInfoCACompatibility/null_ca_field130=== PAUSE TestPathInfoCACompatibility/null_ca_field131=== RUN TestPathInfoCACompatibility/old_string_format_-_text132=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text133=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive134=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive135=== RUN TestPathInfoCACompatibility/new_structured_format_-_text136=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text137=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method138=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method139=== CONT TestParsePathInfoJSONMultiplePaths140=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths141=== CONT TestParsePathInfoJSON142=== RUN TestParsePathInfoJSON/Nix_format143=== PAUSE TestParsePathInfoJSON/Nix_format144=== RUN TestParsePathInfoJSON/Lix_format145=== PAUSE TestParsePathInfoJSON/Lix_format146=== RUN TestParsePathInfoJSON/empty_input147=== PAUSE TestParsePathInfoJSON/empty_input148=== RUN TestParsePathInfoJSON/whitespace_only149=== PAUSE TestParsePathInfoJSON/whitespace_only150=== CONT TestPathInfoHashCompatibility151=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)152=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)153=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon154=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon155=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI156=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI157=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512158=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512159=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error160=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error161=== RUN TestEncodeNixBase32/empty_input162=== PAUSE TestEncodeNixBase32/empty_input163=== CONT TestDumpPathMatchesNix164=== CONT TestDumpPathSingleFile165=== CONT TestFilterOversizedClosures166=== RUN TestFilterOversizedClosures/no_limit_keeps_everything167=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything168=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped169=== CONT TestDumpPathWriterError170=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths171=== RUN TestParsePathInfoJSON/invalid_JSON172=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths173=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped174=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths175--- PASS: TestResolveStorePath (0.00s)176=== CONT TestUploadMultipart_PartsInParallel177=== PAUSE TestParsePathInfoJSON/invalid_JSON178=== RUN TestFilterOversizedClosures/all_closures_skipped179=== PAUSE TestFilterOversizedClosures/all_closures_skipped180=== CONT TestStaticToken181--- PASS: TestStaticToken (0.00s)1822026/09/21 18:17:13 WARN Rate limiter enabled after throttle name=server-test rate=5183=== CONT TestScriptTokenScriptFails1842026/09/21 18:17:13 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:51126185=== CONT TestScriptTokenEmptyCommand186--- PASS: TestScriptTokenEmptyCommand (0.00s)187=== CONT TestScriptTokenBadJSON188=== CONT TestPartSizeForNAR1892026/09/21 18:17:13 WARN Rate limiter backed off name=server-test rate=51902026/09/21 18:17:13 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:51126191=== RUN TestPartSizeForNAR/zero_stays_at_minimum192=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum193=== RUN TestPartSizeForNAR/small_stays_at_minimum194=== PAUSE TestPartSizeForNAR/small_stays_at_minimum195=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum196=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum197=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts198=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts199=== RUN TestPartSizeForNAR/1_TiB200=== PAUSE TestPartSizeForNAR/1_TiB201=== RUN TestPartSizeForNAR/5_TiB_S3_max_object202=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object203=== RUN TestPartSizeForNAR/capped_at_5_GiB204=== PAUSE TestPartSizeForNAR/capped_at_5_GiB205=== CONT TestScriptTokenEmptyToken206--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)207--- PASS: TestDoServerRequestAttachesToken (0.01s)208=== CONT TestScriptTokenCachesUntilRefresh209--- PASS: TestScriptTokenScriptFails (0.00s)210=== CONT TestFileTokenEmpty211=== CONT TestScriptTokenNoExpiryRerunsEveryCall212--- PASS: TestFileTokenEmpty (0.00s)213=== CONT TestFileTokenMissing214--- PASS: TestFileTokenMissing (0.00s)215=== CONT TestFileTokenReadsAndCaches216--- PASS: TestScriptTokenBadJSON (0.01s)217=== CONT TestCaseHackSuffix218--- PASS: TestFileTokenReadsAndCaches (0.00s)219=== CONT TestStreamPushGivesUpOnDeadServer2202026/09/21 18:17:13 ERROR Upload failed error="connection refused" count=202212026/09/21 18:17:13 ERROR Server seems unavailable, giving up on batch untried=17222--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)223=== CONT TestSetClientTLSErrors224=== RUN TestSetClientTLSErrors/missing_cert_file225=== PAUSE TestSetClientTLSErrors/missing_cert_file226=== RUN TestSetClientTLSErrors/missing_key_file227=== PAUSE TestSetClientTLSErrors/missing_key_file228=== RUN TestSetClientTLSErrors/missing_ca_file229=== PAUSE TestSetClientTLSErrors/missing_ca_file230=== RUN TestSetClientTLSErrors/invalid_ca_file231=== PAUSE TestSetClientTLSErrors/invalid_ca_file232=== CONT TestSetClientTLSDoesNotMutateDefaultTransport233--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)234=== CONT TestSetClientTLS235=== RUN TestSetClientTLS/rejects_connection_without_client_cert236=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert237=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA238=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA239=== RUN TestSetClientTLS/preserves_debug_logging_transport240=== PAUSE TestSetClientTLS/preserves_debug_logging_transport241=== CONT TestStreamPushRequestLine2422026/09/21 18:17:13 ERROR Upload failed error=boom count=1243--- PASS: TestScriptTokenEmptyToken (0.01s)244=== CONT TestShellSplitErrors245--- PASS: TestShellSplitErrors (0.00s)246=== CONT TestShellSplit247--- PASS: TestShellSplit (0.00s)248=== CONT TestRegisterUploadedObjectReusesConnections249--- PASS: TestStreamPushRequestLine (0.01s)250=== CONT TestStreamPushIsolatesFailures2512026/09/21 18:17:13 ERROR Upload failed error="bad path" count=3252--- PASS: TestStreamPushIsolatesFailures (0.00s)253=== CONT TestStreamPushBatchesUnderLoad254--- PASS: TestDumpPathWriterError (0.04s)255=== CONT TestStreamPushReportsEveryPath256--- PASS: TestStreamPushReportsEveryPath (0.00s)257=== CONT TestRateLimiterFeedback/429_enables_limiter2582026/09/21 18:17:13 WARN Rate limiter enabled after throttle name=server-test rate=52592026/09/21 18:17:13 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:512032602026/09/21 18:17:13 WARN Rate limiter backed off name=server-test rate=5261=== CONT TestConvertHashToNix32/SRI_format_to_Nix32262=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter263=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter264=== CONT TestRateLimiterFeedback/503_enables_limiter2652026/09/21 18:17:13 WARN Rate limiter enabled after throttle name=server-test rate=52662026/09/21 18:17:13 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:512092672026/09/21 18:17:13 WARN Rate limiter backed off name=server-test rate=5268--- PASS: TestRateLimiterFeedback (0.00s)269 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)270 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)271 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)272 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)273=== CONT TestConvertHashToNix32/invalid_format274=== CONT TestUploadMultipart_SupersededByPeer/exists275--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)276=== CONT TestConvertHashToNix32/already_Nix32_format277--- PASS: TestConvertHashToNix32 (0.00s)278 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)279 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)280 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)281=== CONT TestUploadMultipart_SupersededByPeer/missing282=== CONT TestPathInfoCACompatibility/null_ca_field283=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method284=== CONT TestPathInfoCACompatibility/new_structured_format_-_text285=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestPathInfoCACompatibility/old_string_format_-_text287--- PASS: TestPathInfoCACompatibility (0.00s)288 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)289 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)290 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)291 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)292 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)293=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)294=== CONT TestGetStorePathHash/valid_store_path295=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon296=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI297=== CONT TestEncodeNixBase32/test_string_hash298=== CONT TestGetStorePathHash/basename_without_hyphen_should_error299=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error300=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error301--- PASS: TestGetStorePathHash (0.00s)302 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)303 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)304 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)306=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512307--- PASS: TestPathInfoHashCompatibility (0.00s)308 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)309 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)310 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)311 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)312=== CONT TestEncodeNixBase32/empty_input313--- PASS: TestEncodeNixBase32 (0.00s)314 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)315 --- PASS: TestEncodeNixBase32/empty_input (0.00s)316=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths317=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths318--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)319 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)320 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)321=== CONT TestParsePathInfoJSON/Nix_format322=== CONT TestFilterOversizedClosures/no_limit_keeps_everything323=== CONT TestParsePathInfoJSON/Lix_format324=== CONT TestParsePathInfoJSON/whitespace_only325=== CONT TestParsePathInfoJSON/empty_input326=== CONT TestFilterOversizedClosures/all_closures_skipped327--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)328 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)329 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)330=== CONT TestParsePathInfoJSON/invalid_JSON331=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3322026/09/21 18:17:13 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=2000333=== CONT TestPartSizeForNAR/zero_stays_at_minimum334=== CONT TestPartSizeForNAR/1_TiB3352026/09/21 18:17:13 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50336=== CONT TestPartSizeForNAR/capped_at_5_GiB337=== CONT TestPartSizeForNAR/5_TiB_S3_max_object338=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts339=== CONT TestPartSizeForNAR/small_stays_at_minimum340=== CONT TestSetClientTLSErrors/missing_cert_file341--- PASS: TestFilterOversizedClosures (0.00s)342 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)343 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)344 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)345=== CONT TestSetClientTLSErrors/missing_ca_file346--- PASS: TestParsePathInfoJSON (0.00s)347 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)348 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)349 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)350 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)351 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)352=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum353--- PASS: TestPartSizeForNAR (0.00s)354 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)355 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)356 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)357 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)358 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)359 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)361=== CONT TestSetClientTLSErrors/invalid_ca_file362=== CONT TestSetClientTLSErrors/missing_key_file363=== CONT TestSetClientTLS/rejects_connection_without_client_cert364=== CONT TestSetClientTLS/preserves_debug_logging_transport365--- PASS: TestSetClientTLSErrors (0.00s)366 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)367 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)368 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)369 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)370--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)371=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA372--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)3732026/09/21 18:17:13 http: TLS handshake error from 127.0.0.1:51215: remote error: tls: bad certificate374--- PASS: TestSetClientTLS (0.00s)375 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)376 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)377 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)378--- PASS: TestDumpPathSingleFile (0.06s)379--- PASS: TestCaseHackSuffix (0.05s)380--- PASS: TestDumpPathMatchesNix (0.08s)381--- PASS: TestStreamPushBatchesUnderLoad (0.10s)382--- PASS: TestUploadMultipart_PartsInParallel (0.62s)383--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)384PASS385Running server tests...386The files belonging to this database system will be owned by user "_nixbld10".387This user must also own the server process.388389The database cluster will be initialized with locale "C".390The default database encoding has accordingly been set to "SQL_ASCII".391The default text search configuration will be set to "english".392393Data page checksums are enabled.394395creating directory /nix/var/nix/builds/nix-9315-1570051187/postgres2442361998/data ... ok396creating subdirectories ... ok397selecting dynamic shared memory implementation ... posix398selecting default "max_connections" ... 100399selecting default "shared_buffers" ... 128MB400selecting default time zone ... UTC401creating configuration files ... ok402running bootstrap script ... ok403performing post-bootstrap initialization ... ok404syncing data to disk ... ok405406initdb: warning: enabling "trust" authentication for local connections407initdb: 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.408409Success. You can now start the database server using:410411 pg_ctl -D /nix/var/nix/builds/nix-9315-1570051187/postgres2442361998/data -l logfile start412413/nix/var/nix/builds/nix-9315-1570051187/postgres2442361998:5432 - no response4142026-09-21 18:17:15.348 UTC [9368] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4152026-09-21 18:17:15.348 UTC [9368] LOG: listening on Unix socket "/nix/var/nix/builds/nix-9315-1570051187/postgres2442361998/.s.PGSQL.5432"4162026-09-21 18:17:15.350 UTC [9375] LOG: database system was shut down at 2026-09-21 18:17:15 UTC4172026-09-21 18:17:15.351 UTC [9368] LOG: database system is ready to accept connections418/nix/var/nix/builds/nix-9315-1570051187/postgres2442361998:5432 - accepting connections419{"timestamp":"2026-09-21T18:17:15.565579Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7957a29d-190f-4f50-ac40-ed96e89c87c4","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":430,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}420=== RUN TestService_AuthMiddleware421=== PAUSE TestService_AuthMiddleware422=== RUN TestService_AuthMiddleware_MTLSProxyHeader423=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader424=== RUN TestService_AuthMiddleware_MTLSBoundSubjects425=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects426=== RUN TestService_ReadAuthMiddleware427=== PAUSE TestService_ReadAuthMiddleware428=== RUN TestService_AuthMiddleware_OIDC429=== PAUSE TestService_AuthMiddleware_OIDC430=== RUN TestService_RequireScope_OIDC431=== PAUSE TestService_RequireScope_OIDC432=== RUN TestService_ReadScope_PublicByDefault433=== PAUSE TestService_ReadScope_PublicByDefault434=== RUN TestCacheConfigHandler435=== PAUSE TestCacheConfigHandler436=== RUN TestCacheStatsHandler437=== PAUSE TestCacheStatsHandler438=== RUN TestClientCADerivations439=== PAUSE TestClientCADerivations440=== RUN TestClientErrorHandling441=== PAUSE TestClientErrorHandling442=== RUN TestClientIntegration443=== PAUSE TestClientIntegration444=== RUN TestClientMultipleUploads445=== PAUSE TestClientMultipleUploads446=== RUN TestClientWithDependencies447=== PAUSE TestClientWithDependencies448=== RUN TestClientSharedPathCommittedMidPush449=== PAUSE TestClientSharedPathCommittedMidPush450=== RUN TestPinProtectsFromGC451=== PAUSE TestPinProtectsFromGC452=== RUN TestResolveDBConnectionString453=== PAUSE TestResolveDBConnectionString454=== RUN TestLeadElectsOneAndHandsOver455=== PAUSE TestLeadElectsOneAndHandsOver456=== RUN TestLeadIncumbentWinsAfterRestart4572026-09-21 18:17:15.718 UTC [9447] ERROR: relation "goose_db_version" does not exist at character 364582026-09-21 18:17:15.718 UTC [9447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4592026/09/21 18:17:15 OK 20241026095416_initial_model.sql (3.15ms)4602026/09/21 18:17:15 OK 20251210153512_drop_unused_gin_index.sql (521.25µs)4612026/09/21 18:17:15 OK 20251218171726_add_pins.sql (806.17µs)4622026/09/21 18:17:15 OK 20260628120000_add_object_size_and_stats.sql (776.17µs)4632026/09/21 18:17:15 OK 20260905000000_add_claims.sql (865.58µs)4642026/09/21 18:17:15 OK 20260920000000_drop_claims.sql (564.04µs)4652026/09/21 18:17:15 goose: successfully migrated database to version: 202609200000004662026/09/21 18:17:15 OK 1_commit_pending_closure.sql (763.29µs)4672026/09/21 18:17:15 OK 2_object_stats_trigger.sql (211.58µs)4682026/09/21 18:17:15 goose: up to current file version: 24692026/09/21 18:17:15 INFO lead: acquired remote=192.0.2.1:12344702026/09/21 18:17:16 INFO lead: released remote=192.0.2.1:12344712026/09/21 18:17:16 INFO lead: acquired remote=192.0.2.1:12344722026/09/21 18:17:16 INFO lead: released remote=192.0.2.1:1234473--- PASS: TestLeadIncumbentWinsAfterRestart (0.77s)474=== RUN TestLeadEndsOnShutdown475=== PAUSE TestLeadEndsOnShutdown476=== RUN TestGCAdvisoryLockBlocksConcurrentRun4772026-09-21 18:17:16.522 UTC [9451] ERROR: relation "goose_db_version" does not exist at character 364782026-09-21 18:17:16.522 UTC [9451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4792026/09/21 18:17:16 OK 20241026095416_initial_model.sql (3.58ms)4802026/09/21 18:17:16 OK 20251210153512_drop_unused_gin_index.sql (390.13µs)4812026/09/21 18:17:16 OK 20251218171726_add_pins.sql (816.75µs)4822026/09/21 18:17:16 OK 20260628120000_add_object_size_and_stats.sql (970.29µs)4832026/09/21 18:17:16 OK 20260905000000_add_claims.sql (1.06ms)4842026/09/21 18:17:16 OK 20260920000000_drop_claims.sql (625.71µs)4852026/09/21 18:17:16 goose: successfully migrated database to version: 202609200000004862026/09/21 18:17:16 OK 1_commit_pending_closure.sql (869.96µs)4872026/09/21 18:17:16 OK 2_object_stats_trigger.sql (234.38µs)4882026/09/21 18:17:16 goose: up to current file version: 2489--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)490=== RUN TestGCBugBareHashReferences491=== PAUSE TestGCBugBareHashReferences492=== RUN TestGCMetrics493=== PAUSE TestGCMetrics494=== RUN TestGCTaskStore_StartNew495=== PAUSE TestGCTaskStore_StartNew496=== RUN TestGCTaskStore_DeduplicateSameParams497=== PAUSE TestGCTaskStore_DeduplicateSameParams498=== RUN TestGCTaskStore_ConflictDifferentParams499=== PAUSE TestGCTaskStore_ConflictDifferentParams500=== RUN TestGCTaskStore_GetEmpty501=== PAUSE TestGCTaskStore_GetEmpty502=== RUN TestGCTaskStore_GetReturnsLatest503=== PAUSE TestGCTaskStore_GetReturnsLatest504=== RUN TestGCTaskStore_CompletedAllowsNewTask505=== PAUSE TestGCTaskStore_CompletedAllowsNewTask506=== RUN TestGCTaskStore_PhaseUpdates507=== PAUSE TestGCTaskStore_PhaseUpdates508=== RUN TestGCTaskStore_Fail509=== PAUSE TestGCTaskStore_Fail510=== RUN TestGracefulShutdownDrainsInflight511=== PAUSE TestGracefulShutdownDrainsInflight512=== RUN TestService_healthCheckHandler513=== PAUSE TestService_healthCheckHandler514=== RUN TestService_readinessHandler515=== PAUSE TestService_readinessHandler516=== RUN TestGenerateLandingPage517=== PAUSE TestGenerateLandingPage518=== RUN TestCacheConfigHandlerMaxNarSize519=== PAUSE TestCacheConfigHandlerMaxNarSize520=== RUN TestCreatePendingClosureRejectsOversizedNAR521=== PAUSE TestCreatePendingClosureRejectsOversizedNAR522=== RUN TestNARDeduplicationMetadataUploadBug523=== PAUSE TestNARDeduplicationMetadataUploadBug524=== RUN TestMetricsInventory525=== PAUSE TestMetricsInventory526=== RUN TestService_NativeMTLS527=== PAUSE TestService_NativeMTLS528=== RUN TestServerTLSConfig529=== PAUSE TestServerTLSConfig530=== RUN TestMultipartCleanup531=== PAUSE TestMultipartCleanup532=== RUN TestObjectStatsTrigger533=== PAUSE TestObjectStatsTrigger534=== RUN TestOrphanedObjectsGC535=== PAUSE TestOrphanedObjectsGC536=== RUN TestOrphanedObjectsGCStressTest537=== PAUSE TestOrphanedObjectsGCStressTest538=== RUN TestResurrectedObjectNotDeleted539=== PAUSE TestResurrectedObjectNotDeleted540=== RUN TestCreatePin_ReservedPins541=== PAUSE TestCreatePin_ReservedPins542=== RUN TestParseSingleRange543=== PAUSE TestParseSingleRange544=== RUN TestIsValidCachePath545=== PAUSE TestIsValidCachePath546=== RUN TestReadProxyNarinfo547=== PAUSE TestReadProxyNarinfo548=== RUN TestReadProxyNarinfoAlreadyDecompressed549=== PAUSE TestReadProxyNarinfoAlreadyDecompressed550=== RUN TestReadProxyNarStreaming551=== PAUSE TestReadProxyNarStreaming552=== RUN TestReadProxy404553=== PAUSE TestReadProxy404554=== RUN TestReadProxyInvalidPath555=== PAUSE TestReadProxyInvalidPath556=== RUN TestReadProxyHead557=== PAUSE TestReadProxyHead558=== RUN TestReadProxyConditionalGet559=== PAUSE TestReadProxyConditionalGet560=== RUN TestReadProxyRootRedirectsToIndexHTML561=== PAUSE TestReadProxyRootRedirectsToIndexHTML562=== RUN TestReadProxyDisabled563=== PAUSE TestReadProxyDisabled564=== RUN TestReadRedirectNar565=== PAUSE TestReadRedirectNar566=== RUN TestReadRedirectKeepsNarinfoProxied567=== PAUSE TestReadRedirectKeepsNarinfoProxied568=== RUN TestReadProxyRangeRequest569=== PAUSE TestReadProxyRangeRequest570=== RUN TestReadRedirectUsesPublicS3URL571=== PAUSE TestReadRedirectUsesPublicS3URL572=== RUN TestRedundantMultipartUpload573=== PAUSE TestRedundantMultipartUpload574=== RUN TestCompleteMultipartUpload_ErrorButObjectExists575=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists576=== RUN TestCompletedNarNotReofferedAcrossClosures577=== PAUSE TestCompletedNarNotReofferedAcrossClosures578=== RUN TestPresignedUploadRegisteredBeforeCommit579=== PAUSE TestPresignedUploadRegisteredBeforeCommit580=== RUN TestService_Rustfstest581=== PAUSE TestService_Rustfstest582=== RUN TestParseSize583=== PAUSE TestParseSize584=== RUN TestSkippedUploadsHandler585=== PAUSE TestSkippedUploadsHandler586=== RUN TestSystemdListenerNotActivated587--- PASS: TestSystemdListenerNotActivated (0.00s)588=== RUN TestWatchdogBeatsWhenHealthy589--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)590=== RUN TestWatchdogSkipsWhenUnhealthy5912026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5972026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5982026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5992026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6002026/09/21 18:17:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"601--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)602=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle603=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle604=== RUN TestProxyWriteTimeout605=== PAUSE TestProxyWriteTimeout606=== RUN TestIsValidUploadKey607=== PAUSE TestIsValidUploadKey608=== RUN TestUploadHandlersRejectInvalidKeys609=== PAUSE TestUploadHandlersRejectInvalidKeys610=== RUN TestUploadHandlersRejectOversizedBody611=== PAUSE TestUploadHandlersRejectOversizedBody612=== RUN TestService_cleanupPendingClosuresHandler613=== PAUSE TestService_cleanupPendingClosuresHandler614=== RUN TestService_createPendingClosureHandler615=== PAUSE TestService_createPendingClosureHandler616=== RUN TestService_verifyS3Integrity617=== PAUSE TestService_verifyS3Integrity618=== RUN TestCompleteMultipartUnregistered619=== PAUSE TestCompleteMultipartUnregistered620=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT621=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT622=== CONT TestReadRedirectNar623=== CONT TestService_AuthMiddleware624=== CONT TestGCTaskStore_Fail625--- PASS: TestGCTaskStore_Fail (0.00s)626=== CONT TestReadProxyDisabled627=== CONT TestClientSharedPathCommittedMidPush628=== CONT TestCacheConfigHandler629=== RUN TestCacheConfigHandler/full_config,_no_issuer630=== PAUSE TestCacheConfigHandler/full_config,_no_issuer631=== RUN TestCacheConfigHandler/no_cache_url_configured632=== PAUSE TestCacheConfigHandler/no_cache_url_configured633=== RUN TestCacheConfigHandler/no_signing_keys634=== PAUSE TestCacheConfigHandler/no_signing_keys635=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator636=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator637=== CONT TestGCTaskStore_ConflictDifferentParams638--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)639=== CONT TestGCTaskStore_DeduplicateSameParams640--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)641=== CONT TestClientIntegration642=== CONT TestGCTaskStore_StartNew643--- PASS: TestGCTaskStore_StartNew (0.00s)644=== CONT TestClientWithDependencies645=== CONT TestGCTaskStore_PhaseUpdates646--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)647=== CONT TestClientMultipleUploads648=== CONT TestGCTaskStore_CompletedAllowsNewTask649=== CONT TestGCTaskStore_GetReturnsLatest650=== CONT TestGCTaskStore_GetEmpty651=== CONT TestGCBugBareHashReferences652=== CONT TestGCMetrics653--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)654--- PASS: TestGCTaskStore_GetEmpty (0.00s)655--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)656=== CONT TestLeadEndsOnShutdown6572026-09-21 18:17:17.162 UTC [9474] ERROR: relation "goose_db_version" does not exist at character 366582026-09-21 18:17:17.162 UTC [9474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6592026-09-21 18:17:17.162 UTC [9475] ERROR: relation "goose_db_version" does not exist at character 366602026-09-21 18:17:17.162 UTC [9475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6612026-09-21 18:17:17.162 UTC [9476] ERROR: relation "goose_db_version" does not exist at character 366622026-09-21 18:17:17.162 UTC [9476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6632026-09-21 18:17:17.162 UTC [9477] ERROR: relation "goose_db_version" does not exist at character 366642026-09-21 18:17:17.162 UTC [9477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-09-21 18:17:17.164 UTC [9478] ERROR: relation "goose_db_version" does not exist at character 366662026-09-21 18:17:17.164 UTC [9478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026-09-21 18:17:17.164 UTC [9480] ERROR: relation "goose_db_version" does not exist at character 366682026-09-21 18:17:17.164 UTC [9480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6692026-09-21 18:17:17.164 UTC [9481] ERROR: relation "goose_db_version" does not exist at character 366702026-09-21 18:17:17.164 UTC [9481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6712026-09-21 18:17:17.165 UTC [9479] ERROR: relation "goose_db_version" does not exist at character 366722026-09-21 18:17:17.165 UTC [9479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6732026-09-21 18:17:17.167 UTC [9482] ERROR: relation "goose_db_version" does not exist at character 366742026-09-21 18:17:17.167 UTC [9482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6752026-09-21 18:17:17.167 UTC [9483] ERROR: relation "goose_db_version" does not exist at character 366762026-09-21 18:17:17.167 UTC [9483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6772026/09/21 18:17:17 OK 20241026095416_initial_model.sql (8.31ms)6782026/09/21 18:17:17 OK 20241026095416_initial_model.sql (7.8ms)6792026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (818.04µs)6802026/09/21 18:17:17 OK 20241026095416_initial_model.sql (8.43ms)6812026/09/21 18:17:17 OK 20241026095416_initial_model.sql (8.64ms)6822026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (760.08µs)6832026/09/21 18:17:17 OK 20241026095416_initial_model.sql (7.77ms)6842026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (809.63µs)6852026/09/21 18:17:17 OK 20241026095416_initial_model.sql (8.2ms)6862026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (839.08µs)6872026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)6882026/09/21 18:17:17 OK 20251218171726_add_pins.sql (1.87ms)6892026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)6902026/09/21 18:17:17 OK 20251218171726_add_pins.sql (2.02ms)6912026/09/21 18:17:17 OK 20251218171726_add_pins.sql (1.84ms)6922026/09/21 18:17:17 OK 20241026095416_initial_model.sql (6.99ms)6932026/09/21 18:17:17 OK 20241026095416_initial_model.sql (8.26ms)6942026/09/21 18:17:17 OK 20241026095416_initial_model.sql (9.49ms)6952026/09/21 18:17:17 OK 20251218171726_add_pins.sql (2.28ms)6962026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.74ms)6972026/09/21 18:17:17 OK 20251218171726_add_pins.sql (1.5ms)6982026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (610.71µs)6992026/09/21 18:17:17 OK 20241026095416_initial_model.sql (8.9ms)7002026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.44ms)7012026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.39ms)7022026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (842.71µs)7032026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (745.88µs)7042026/09/21 18:17:17 OK 20251218171726_add_pins.sql (2.53ms)7052026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (591.33µs)7062026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.56ms)7072026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)7082026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.57ms)7092026/09/21 18:17:17 OK 20251218171726_add_pins.sql (1.75ms)7102026/09/21 18:17:17 OK 20260905000000_add_claims.sql (2.46ms)7112026/09/21 18:17:17 OK 20251218171726_add_pins.sql (2.1ms)7122026/09/21 18:17:17 OK 20251218171726_add_pins.sql (1.8ms)7132026/09/21 18:17:17 OK 20260905000000_add_claims.sql (2.03ms)7142026/09/21 18:17:17 OK 20260905000000_add_claims.sql (2.21ms)7152026/09/21 18:17:17 OK 20251218171726_add_pins.sql (2.34ms)7162026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.02ms)7172026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007182026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.33ms)7192026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)7202026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.49ms)7212026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007222026/09/21 18:17:17 OK 20260905000000_add_claims.sql (2.17ms)7232026/09/21 18:17:17 OK 20260905000000_add_claims.sql (2.56ms)7242026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (2.14ms)7252026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.97ms)7262026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007272026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (1.45ms)7282026/09/21 18:17:17 OK 20260905000000_add_claims.sql (2.5ms)7292026/09/21 18:17:17 OK 1_commit_pending_closure.sql (1.58ms)7302026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.2ms)7312026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007322026/09/21 18:17:17 OK 20260905000000_add_claims.sql (1.59ms)7332026/09/21 18:17:17 OK 20260905000000_add_claims.sql (1.64ms)7342026/09/21 18:17:17 OK 2_object_stats_trigger.sql (602.13µs)7352026/09/21 18:17:17 goose: up to current file version: 27362026/09/21 18:17:17 OK 1_commit_pending_closure.sql (1.92ms)7372026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.16ms)7382026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007392026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.84ms)7402026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007412026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (943.33µs)7422026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007432026/09/21 18:17:17 OK 1_commit_pending_closure.sql (1.71ms)7442026/09/21 18:17:17 OK 20260905000000_add_claims.sql (1.66ms)7452026/09/21 18:17:17 OK 20260905000000_add_claims.sql (1.85ms)7462026/09/21 18:17:17 OK 1_commit_pending_closure.sql (1.21ms)7472026/09/21 18:17:17 OK 2_object_stats_trigger.sql (739.04µs)7482026/09/21 18:17:17 goose: up to current file version: 27492026/09/21 18:17:17 OK 2_object_stats_trigger.sql (393.96µs)7502026/09/21 18:17:17 goose: up to current file version: 27512026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.35ms)7522026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007532026/09/21 18:17:17 OK 1_commit_pending_closure.sql (861.63µs)7542026/09/21 18:17:17 OK 1_commit_pending_closure.sql (772.75µs)7552026/09/21 18:17:17 OK 2_object_stats_trigger.sql (565.33µs)7562026/09/21 18:17:17 goose: up to current file version: 27572026/09/21 18:17:17 OK 1_commit_pending_closure.sql (1.44ms)7582026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (998.42µs)7592026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007602026/09/21 18:17:17 OK 2_object_stats_trigger.sql (365.42µs)7612026/09/21 18:17:17 goose: up to current file version: 27622026/09/21 18:17:17 OK 2_object_stats_trigger.sql (443.46µs)7632026/09/21 18:17:17 goose: up to current file version: 27642026/09/21 18:17:17 OK 2_object_stats_trigger.sql (266.25µs)7652026/09/21 18:17:17 goose: up to current file version: 27662026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (1.31ms)7672026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000007682026/09/21 18:17:17 OK 1_commit_pending_closure.sql (829.96µs)7692026/09/21 18:17:17 OK 2_object_stats_trigger.sql (198.88µs)7702026/09/21 18:17:17 goose: up to current file version: 27712026/09/21 18:17:17 OK 1_commit_pending_closure.sql (707.54µs)7722026/09/21 18:17:17 OK 2_object_stats_trigger.sql (171.42µs)7732026/09/21 18:17:17 goose: up to current file version: 27742026/09/21 18:17:17 OK 1_commit_pending_closure.sql (664.42µs)7752026/09/21 18:17:17 OK 2_object_stats_trigger.sql (197.21µs)7762026/09/21 18:17:17 goose: up to current file version: 27772026/09/21 18:17:17 INFO lead: acquired remote=192.0.2.1:12347782026/09/21 18:17:17 INFO lead: released remote=192.0.2.1:1234779--- PASS: TestLeadEndsOnShutdown (0.43s)780=== CONT TestResolveDBConnectionString781=== RUN TestResolveDBConnectionString/flag_wins782=== PAUSE TestResolveDBConnectionString/flag_wins783=== RUN TestResolveDBConnectionString/file_when_flag_empty784=== PAUSE TestResolveDBConnectionString/file_when_flag_empty785=== RUN TestResolveDBConnectionString/missing_file_is_an_error786=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error787=== RUN TestResolveDBConnectionString/PGHOST_allows_empty788=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty789=== RUN TestResolveDBConnectionString/nothing_configured790=== PAUSE TestResolveDBConnectionString/nothing_configured791=== CONT TestLeadElectsOneAndHandsOver7922026/09/21 18:17:17 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"793--- PASS: TestService_AuthMiddleware (0.55s)794=== CONT TestReadProxyRootRedirectsToIndexHTML795--- PASS: TestReadRedirectNar (0.69s)796=== CONT TestReadProxyConditionalGet7972026-09-21 18:17:17.826 UTC [9493] ERROR: relation "goose_db_version" does not exist at character 367982026-09-21 18:17:17.826 UTC [9493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-09-21 18:17:17.863 UTC [9496] ERROR: relation "goose_db_version" does not exist at character 368002026-09-21 18:17:17.863 UTC [9496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/09/21 18:17:17 OK 20241026095416_initial_model.sql (28.92ms)8022026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (6.8ms)8032026/09/21 18:17:17 OK 20251218171726_add_pins.sql (5.64ms)8042026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (6.52ms)8052026/09/21 18:17:17 OK 20260905000000_add_claims.sql (10.6ms)8062026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (9.48ms)8072026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000008082026/09/21 18:17:17 OK 1_commit_pending_closure.sql (979.04µs)8092026/09/21 18:17:17 OK 2_object_stats_trigger.sql (245.79µs)8102026/09/21 18:17:17 goose: up to current file version: 28112026/09/21 18:17:17 OK 20241026095416_initial_model.sql (32.31ms)8122026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (4.52ms)8132026/09/21 18:17:17 OK 20251218171726_add_pins.sql (12.83ms)8142026/09/21 18:17:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8152026/09/21 18:17:17 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)8162026/09/21 18:17:17 OK 20260905000000_add_claims.sql (1.35ms)8172026/09/21 18:17:17 OK 20260920000000_drop_claims.sql (8.76ms)8182026/09/21 18:17:17 goose: successfully migrated database to version: 202609200000008192026-09-21 18:17:17.941 UTC [9501] ERROR: relation "goose_db_version" does not exist at character 368202026-09-21 18:17:17.941 UTC [9501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/09/21 18:17:17 OK 1_commit_pending_closure.sql (1.04ms)8222026/09/21 18:17:17 OK 2_object_stats_trigger.sql (250.13µs)8232026/09/21 18:17:17 goose: up to current file version: 28242026/09/21 18:17:17 INFO Received uploads request method=POST path=/api/pending_closures8252026/09/21 18:17:17 OK 20241026095416_initial_model.sql (25.48ms)8262026/09/21 18:17:17 OK 20251210153512_drop_unused_gin_index.sql (8.14ms)8272026/09/21 18:17:17 OK 20251218171726_add_pins.sql (4ms)8282026/09/21 18:17:18 OK 20260628120000_add_object_size_and_stats.sql (14.06ms)829--- PASS: TestGCBugBareHashReferences (1.19s)830=== CONT TestReadProxyHead831=== NAME TestClientMultipleUploads832 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-9315-1570051187/TestClientMultipleUploads1280900210/001/store/lc94n9bn9lfby6vq8mb5iy093y8aglaz-test-file-0.txt8332026/09/21 18:17:18 OK 20260905000000_add_claims.sql (14.1ms)8342026/09/21 18:17:18 OK 20260920000000_drop_claims.sql (11.34ms)8352026/09/21 18:17:18 goose: successfully migrated database to version: 202609200000008362026/09/21 18:17:18 OK 1_commit_pending_closure.sql (1.08ms)8372026/09/21 18:17:18 OK 2_object_stats_trigger.sql (234.58µs)8382026/09/21 18:17:18 goose: up to current file version: 28392026/09/21 18:17:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"840--- PASS: TestReadProxyDisabled (1.24s)841=== CONT TestReadProxyInvalidPath842=== NAME TestClientMultipleUploads843 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-9315-1570051187/TestClientMultipleUploads1280900210/001/store/qj4nj75r1pmmms9k8aklj53idns1iqp8-test-file-1.txt8442026/09/21 18:17:18 INFO Received uploads request method=POST path=/api/pending_closures8452026/09/21 18:17:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8462026/09/21 18:17:18 INFO Uploading if2mkzr8yy6rql8h76d9cnl8n0al7qav-shared-dep (136B)8472026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8482026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8492026/09/21 18:17:18 WARN Failed to register uploaded object key=if2mkzr8yy6rql8h76d9cnl8n0al7qav.ls error="server returned 404: 404 page not found\n"8502026/09/21 18:17:18 INFO Signed narinfos id=2 count=18512026/09/21 18:17:18 INFO Uploading 1 narinfos8522026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8532026/09/21 18:17:18 WARN Failed to register uploaded object key=if2mkzr8yy6rql8h76d9cnl8n0al7qav.narinfo error="server returned 404: 404 page not found\n"8542026/09/21 18:17:18 INFO Completed upload id=2855 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-9315-1570051187/TestClientMultipleUploads1280900210/001/store/fxfxrhjjc9riqrk9nsbdvy6gi532xdl3-test-file-2.txt8562026/09/21 18:17:18 INFO Upload complete. (98ms)8572026/09/21 18:17:18 INFO Received uploads request method=POST path=/api/pending_closures8582026/09/21 18:17:18 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)8592026/09/21 18:17:18 INFO Uploading zz9nq53c8539q92bpkb8qqdpjbi6gvh7-top (256B)8602026/09/21 18:17:18 INFO Uploading if2mkzr8yy6rql8h76d9cnl8n0al7qav-shared-dep (136B)8612026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/1aqxf20r27a027a4992bhafdqcl27cay3znq6jz2x2xhdya7k541.nar.zst error="server returned 404: 404 page not found\n"8622026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8632026/09/21 18:17:18 WARN Failed to register uploaded object key=zz9nq53c8539q92bpkb8qqdpjbi6gvh7.ls error="server returned 404: 404 page not found\n"8642026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign8652026/09/21 18:17:18 WARN Failed to register uploaded object key=if2mkzr8yy6rql8h76d9cnl8n0al7qav.ls error="server returned 404: 404 page not found\n"8662026/09/21 18:17:18 INFO Signed narinfos id=3 count=18672026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8682026/09/21 18:17:18 INFO Signed narinfos id=1 count=18692026/09/21 18:17:18 INFO Uploading 2 narinfos8702026/09/21 18:17:18 WARN Failed to register uploaded object key=zz9nq53c8539q92bpkb8qqdpjbi6gvh7.narinfo error="server returned 404: 404 page not found\n"8712026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8722026/09/21 18:17:18 WARN Failed to register uploaded object key=if2mkzr8yy6rql8h76d9cnl8n0al7qav.narinfo error="server returned 404: 404 page not found\n"8732026/09/21 18:17:18 INFO Completed upload id=18742026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete8752026/09/21 18:17:18 INFO Completed upload id=38762026/09/21 18:17:18 INFO Upload complete. (245ms)877=== NAME TestClientSharedPathCommittedMidPush878 client_integration_test.go:680: Retrieved narinfo from S3:879 StorePath: /nix/var/nix/builds/nix-9315-1570051187/TestClientSharedPathCommittedMidPush538138648/001/store/if2mkzr8yy6rql8h76d9cnl8n0al7qav-shared-dep880 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst881 Compression: zstd882 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82883 NarSize: 136884 References: 885 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n886 client_integration_test.go:680: Retrieved narinfo from S3:887 StorePath: /nix/var/nix/builds/nix-9315-1570051187/TestClientSharedPathCommittedMidPush538138648/001/store/zz9nq53c8539q92bpkb8qqdpjbi6gvh7-top888 URL: nar/1aqxf20r27a027a4992bhafdqcl27cay3znq6jz2x2xhdya7k541.nar.zst889 Compression: zstd890 NarHash: sha256:1aqxf20r27a027a4992bhafdqcl27cay3znq6jz2x2xhdya7k541891 NarSize: 256892 References: /nix/var/nix/builds/nix-9315-1570051187/TestClientSharedPathCommittedMidPush538138648/001/store/if2mkzr8yy6rql8h76d9cnl8n0al7qav-shared-dep893 CA: text:sha256:1zh0f605ivwyxqdfbrcyvy0aw0aj4yf9sdhsylplgwwj1yahjs1d894--- PASS: TestClientSharedPathCommittedMidPush (1.33s)895=== CONT TestReadProxy4048962026/09/21 18:17:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8972026/09/21 18:17:18 INFO Received uploads request method=POST path=/api/pending_closures8982026/09/21 18:17:18 INFO Received uploads request method=POST path=/api/pending_closures8992026/09/21 18:17:18 INFO Received uploads request method=POST path=/api/pending_closures9002026/09/21 18:17:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)9012026/09/21 18:17:18 INFO Uploading fxfxrhjjc9riqrk9nsbdvy6gi532xdl3-test-file-2.txt (160B)9022026/09/21 18:17:18 INFO Uploading lc94n9bn9lfby6vq8mb5iy093y8aglaz-test-file-0.txt (160B)9032026/09/21 18:17:18 INFO Uploading qj4nj75r1pmmms9k8aklj53idns1iqp8-test-file-1.txt (160B)9042026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"9052026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"9062026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"9072026/09/21 18:17:18 WARN Failed to register uploaded object key=lc94n9bn9lfby6vq8mb5iy093y8aglaz.ls error="server returned 404: 404 page not found\n"9082026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9092026/09/21 18:17:18 WARN Failed to register uploaded object key=fxfxrhjjc9riqrk9nsbdvy6gi532xdl3.ls error="server returned 404: 404 page not found\n"9102026/09/21 18:17:18 WARN Failed to register uploaded object key=qj4nj75r1pmmms9k8aklj53idns1iqp8.ls error="server returned 404: 404 page not found\n"9112026/09/21 18:17:18 INFO Signed narinfos id=2 count=19122026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign9132026/09/21 18:17:18 INFO Signed narinfos id=3 count=19142026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9152026/09/21 18:17:18 INFO Signed narinfos id=1 count=19162026/09/21 18:17:18 INFO Uploading 3 narinfos9172026/09/21 18:17:18 WARN Failed to register uploaded object key=lc94n9bn9lfby6vq8mb5iy093y8aglaz.narinfo error="server returned 404: 404 page not found\n"9182026/09/21 18:17:18 WARN Failed to register uploaded object key=qj4nj75r1pmmms9k8aklj53idns1iqp8.narinfo error="server returned 404: 404 page not found\n"9192026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9202026/09/21 18:17:18 WARN Failed to register uploaded object key=fxfxrhjjc9riqrk9nsbdvy6gi532xdl3.narinfo error="server returned 404: 404 page not found\n"9212026/09/21 18:17:18 INFO Completed upload id=29222026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete9232026/09/21 18:17:18 INFO Completed upload id=39242026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9252026/09/21 18:17:18 INFO Completed upload id=19262026/09/21 18:17:18 INFO Upload complete. (150ms)927=== NAME TestClientMultipleUploads928 client_integration_test.go:369: Uploaded 3 paths in 182.58575ms929--- PASS: TestClientMultipleUploads (1.49s)930=== CONT TestReadProxyNarStreaming9312026-09-21 18:17:18.375 UTC [9536] ERROR: relation "goose_db_version" does not exist at character 369322026-09-21 18:17:18.375 UTC [9536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC933=== NAME TestClientIntegration934 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-9315-1570051187/TestClientIntegration2706900427/002/store/mirbk6lplsx989zkvmc3i06q4jq4sapr-test-file.txt935=== NAME TestClientWithDependencies936 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-9315-1570051187/TestClientWithDependencies317635436/001/store/1lqm3yn63nma9vprxnfx8y465rgj8c9j-test-script9372026/09/21 18:17:18 OK 20241026095416_initial_model.sql (35.97ms)9382026/09/21 18:17:18 INFO Aborted multipart uploads count=09392026/09/21 18:17:18 WARN Force mode enabled - objects will be deleted immediately without grace period9402026/09/21 18:17:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09412026/09/21 18:17:18 INFO Vacuumed table table=pending_closures9422026/09/21 18:17:18 INFO Vacuumed table table=pending_objects9432026/09/21 18:17:18 INFO Vacuumed table table=multipart_uploads9442026/09/21 18:17:18 INFO Vacuumed table table=closures9452026/09/21 18:17:18 INFO Vacuumed table table=objects946--- PASS: TestGCMetrics (1.62s)947=== CONT TestReadProxyNarinfoAlreadyDecompressed9482026/09/21 18:17:18 OK 20251210153512_drop_unused_gin_index.sql (5.44ms)9492026/09/21 18:17:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9502026/09/21 18:17:18 OK 20251218171726_add_pins.sql (12.33ms)951=== NAME TestClientWithDependencies952 client_integration_test.go:615: Found 1 dependencies (including self)9532026/09/21 18:17:18 OK 20260628120000_add_object_size_and_stats.sql (8.43ms)9542026/09/21 18:17:18 OK 20260905000000_add_claims.sql (24.99ms)9552026/09/21 18:17:18 INFO Received uploads request method=POST path=/api/pending_closures9562026/09/21 18:17:18 OK 20260920000000_drop_claims.sql (2.01ms)9572026/09/21 18:17:18 goose: successfully migrated database to version: 202609200000009582026/09/21 18:17:18 OK 1_commit_pending_closure.sql (961.21µs)9592026/09/21 18:17:18 OK 2_object_stats_trigger.sql (213.88µs)9602026/09/21 18:17:18 goose: up to current file version: 29612026/09/21 18:17:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9622026/09/21 18:17:18 INFO Uploading mirbk6lplsx989zkvmc3i06q4jq4sapr-test-file.txt (152B)9632026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9642026-09-21 18:17:18.517 UTC [9551] ERROR: relation "goose_db_version" does not exist at character 369652026-09-21 18:17:18.517 UTC [9551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9662026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9672026/09/21 18:17:18 WARN Failed to register uploaded object key=mirbk6lplsx989zkvmc3i06q4jq4sapr.ls error="server returned 404: 404 page not found\n"9682026/09/21 18:17:18 INFO Signed narinfos id=1 count=19692026/09/21 18:17:18 INFO Uploading 1 narinfos9702026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9712026/09/21 18:17:18 WARN Failed to register uploaded object key=mirbk6lplsx989zkvmc3i06q4jq4sapr.narinfo error="server returned 404: 404 page not found\n"9722026/09/21 18:17:18 INFO Completed upload id=19732026/09/21 18:17:18 INFO Upload complete. (133ms)9742026/09/21 18:17:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9752026/09/21 18:17:18 INFO Received uploads request method=POST path=/api/pending_closures9762026/09/21 18:17:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9772026/09/21 18:17:18 INFO Uploading 1lqm3yn63nma9vprxnfx8y465rgj8c9j-test-script (136B)9782026/09/21 18:17:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9792026/09/21 18:17:18 INFO lead: acquired remote=192.0.2.1:12349802026/09/21 18:17:18 WARN Failed to register uploaded object key=log/f0bg83fxkbpi3q7mba67j8ylqqnccm6f-test-script.drv error="server returned 404: 404 page not found\n"9812026/09/21 18:17:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9822026/09/21 18:17:18 WARN Failed to register uploaded object key=1lqm3yn63nma9vprxnfx8y465rgj8c9j.ls error="server returned 404: 404 page not found\n"9832026/09/21 18:17:18 INFO Signed narinfos id=1 count=19842026/09/21 18:17:18 INFO Uploading 1 narinfos9852026/09/21 18:17:18 OK 20241026095416_initial_model.sql (34.26ms)9862026/09/21 18:17:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9872026/09/21 18:17:18 WARN Failed to register uploaded object key=1lqm3yn63nma9vprxnfx8y465rgj8c9j.narinfo error="server returned 404: 404 page not found\n"9882026/09/21 18:17:18 INFO All 1 paths already cached989=== NAME TestClientIntegration990 client_integration_test.go:312: Retrieved narinfo from S3:991 StorePath: /nix/var/nix/builds/nix-9315-1570051187/TestClientIntegration2706900427/002/store/mirbk6lplsx989zkvmc3i06q4jq4sapr-test-file.txt992 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst993 Compression: zstd994 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1995 NarSize: 152996 References: 997 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1998 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)999 client_integration_test.go:313: Decompressed .ls content (64 bytes):1000 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1001 client_integration_test.go:316: Testing garbage collection...10022026/09/21 18:17:18 OK 20251210153512_drop_unused_gin_index.sql (11.25ms)10032026/09/21 18:17:18 INFO Completed upload id=110042026/09/21 18:17:18 INFO Upload complete. (97ms)10052026/09/21 18:17:18 OK 20251218171726_add_pins.sql (13.35ms)1006=== NAME TestClientWithDependencies1007 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-9315-1570051187/TestClientWithDependencies317635436/001/store) requires matching store prefix10082026/09/21 18:17:18 OK 20260628120000_add_object_size_and_stats.sql (7.49ms)10092026/09/21 18:17:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures10102026/09/21 18:17:18 INFO Garbage collection started10112026/09/21 18:17:18 INFO Aborted multipart uploads count=010122026/09/21 18:17:18 WARN Force mode enabled - objects will be deleted immediately without grace period10132026/09/21 18:17:18 OK 20260905000000_add_claims.sql (12.61ms)1014--- PASS: TestClientWithDependencies (1.80s)1015=== CONT TestReadProxyNarinfo10162026/09/21 18:17:18 OK 20260920000000_drop_claims.sql (7.04ms)10172026/09/21 18:17:18 goose: successfully migrated database to version: 2026092000000010182026/09/21 18:17:18 OK 1_commit_pending_closure.sql (953.71µs)10192026/09/21 18:17:18 OK 2_object_stats_trigger.sql (312.75µs)10202026/09/21 18:17:18 goose: up to current file version: 21021--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.32s)1022=== CONT TestIsValidCachePath1023=== RUN TestIsValidCachePath/narinfo1024=== PAUSE TestIsValidCachePath/narinfo1025=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1026=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1027=== RUN TestIsValidCachePath/nar_zst1028=== PAUSE TestIsValidCachePath/nar_zst1029=== RUN TestIsValidCachePath/nar_xz1030=== PAUSE TestIsValidCachePath/nar_xz1031=== RUN TestIsValidCachePath/nar_bz21032=== PAUSE TestIsValidCachePath/nar_bz21033=== RUN TestIsValidCachePath/nar_uncompressed1034=== PAUSE TestIsValidCachePath/nar_uncompressed1035=== RUN TestIsValidCachePath/ls1036=== PAUSE TestIsValidCachePath/ls1037=== RUN TestIsValidCachePath/log1038=== PAUSE TestIsValidCachePath/log1039=== RUN TestIsValidCachePath/realisation1040=== PAUSE TestIsValidCachePath/realisation1041=== RUN TestIsValidCachePath/nix-cache-info1042=== PAUSE TestIsValidCachePath/nix-cache-info1043=== RUN TestIsValidCachePath/index.html1044=== PAUSE TestIsValidCachePath/index.html1045=== RUN TestIsValidCachePath/traversal_parent1046=== PAUSE TestIsValidCachePath/traversal_parent1047=== RUN TestIsValidCachePath/traversal_in_middle1048=== PAUSE TestIsValidCachePath/traversal_in_middle1049=== RUN TestIsValidCachePath/invalid_char_e1050=== PAUSE TestIsValidCachePath/invalid_char_e1051=== RUN TestIsValidCachePath/invalid_char_u1052=== PAUSE TestIsValidCachePath/invalid_char_u1053=== RUN TestIsValidCachePath/random_path1054=== PAUSE TestIsValidCachePath/random_path1055=== RUN TestIsValidCachePath/empty1056=== PAUSE TestIsValidCachePath/empty1057=== RUN TestIsValidCachePath/leading_slash1058=== PAUSE TestIsValidCachePath/leading_slash1059=== RUN TestIsValidCachePath/wrong_extension1060=== PAUSE TestIsValidCachePath/wrong_extension1061=== RUN TestIsValidCachePath/short_hash1062=== PAUSE TestIsValidCachePath/short_hash1063=== CONT TestParseSingleRange1064=== RUN TestParseSingleRange/none1065=== PAUSE TestParseSingleRange/none1066=== RUN TestParseSingleRange/unknown_unit1067=== PAUSE TestParseSingleRange/unknown_unit1068=== RUN TestParseSingleRange/multi-range_ignored1069=== PAUSE TestParseSingleRange/multi-range_ignored1070=== RUN TestParseSingleRange/malformed_no_dash1071=== PAUSE TestParseSingleRange/malformed_no_dash1072=== RUN TestParseSingleRange/malformed_both_empty1073=== PAUSE TestParseSingleRange/malformed_both_empty1074=== RUN TestParseSingleRange/malformed_end_before_start1075=== PAUSE TestParseSingleRange/malformed_end_before_start1076=== RUN TestParseSingleRange/closed1077=== PAUSE TestParseSingleRange/closed1078=== RUN TestParseSingleRange/open-ended1079=== PAUSE TestParseSingleRange/open-ended1080=== RUN TestParseSingleRange/end_clamped_to_size1081=== PAUSE TestParseSingleRange/end_clamped_to_size1082=== RUN TestParseSingleRange/suffix1083=== PAUSE TestParseSingleRange/suffix1084=== RUN TestParseSingleRange/suffix_exceeds_size1085=== PAUSE TestParseSingleRange/suffix_exceeds_size1086=== RUN TestParseSingleRange/single_byte1087=== PAUSE TestParseSingleRange/single_byte1088=== RUN TestParseSingleRange/start_past_EOF1089=== PAUSE TestParseSingleRange/start_past_EOF1090=== RUN TestParseSingleRange/start_far_past_EOF1091=== PAUSE TestParseSingleRange/start_far_past_EOF1092=== CONT TestCreatePin_ReservedPins10932026/09/21 18:17:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51278/oidc10942026/09/21 18:17:18 INFO lead: released remote=192.0.2.1:123410952026-09-21 18:17:18.733 UTC [9563] ERROR: relation "goose_db_version" does not exist at character 3610962026-09-21 18:17:18.733 UTC [9563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10972026/09/21 18:17:18 INFO lead: acquired remote=192.0.2.1:123410982026/09/21 18:17:18 INFO lead: released remote=192.0.2.1:12341099--- PASS: TestLeadElectsOneAndHandsOver (1.52s)1100=== CONT TestResurrectedObjectNotDeleted11012026/09/21 18:17:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2094 objects-failed-to-delete=011022026/09/21 18:17:18 INFO Vacuumed table table=pending_closures11032026/09/21 18:17:18 INFO Vacuumed table table=pending_objects11042026/09/21 18:17:18 INFO Vacuumed table table=multipart_uploads11052026/09/21 18:17:18 OK 20241026095416_initial_model.sql (81.15ms)11062026/09/21 18:17:18 INFO Vacuumed table table=closures11072026/09/21 18:17:18 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)11082026/09/21 18:17:18 OK 20251218171726_add_pins.sql (2.16ms)1109--- PASS: TestReadProxyConditionalGet (1.34s)1110=== CONT TestOrphanedObjectsGCStressTest11112026/09/21 18:17:18 INFO Vacuumed table table=objects11122026/09/21 18:17:18 OK 20260628120000_add_object_size_and_stats.sql (15.81ms)11132026-09-21 18:17:18.868 UTC [9570] ERROR: relation "goose_db_version" does not exist at character 3611142026-09-21 18:17:18.868 UTC [9570] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11152026/09/21 18:17:18 OK 20260905000000_add_claims.sql (12.86ms)11162026/09/21 18:17:18 OK 20260920000000_drop_claims.sql (12.52ms)11172026/09/21 18:17:18 goose: successfully migrated database to version: 2026092000000011182026/09/21 18:17:18 OK 1_commit_pending_closure.sql (1.11ms)11192026/09/21 18:17:18 OK 2_object_stats_trigger.sql (220µs)11202026/09/21 18:17:18 goose: up to current file version: 211212026/09/21 18:17:18 OK 20241026095416_initial_model.sql (40.99ms)11222026/09/21 18:17:18 OK 20251210153512_drop_unused_gin_index.sql (10.63ms)11232026/09/21 18:17:18 OK 20251218171726_add_pins.sql (8.82ms)11242026/09/21 18:17:18 OK 20260628120000_add_object_size_and_stats.sql (17.81ms)11252026/09/21 18:17:18 OK 20260905000000_add_claims.sql (6.57ms)11262026/09/21 18:17:18 OK 20260920000000_drop_claims.sql (2.07ms)11272026/09/21 18:17:18 goose: successfully migrated database to version: 202609200000001128--- PASS: TestReadProxyHead (0.96s)1129=== CONT TestOrphanedObjectsGC11302026/09/21 18:17:18 OK 1_commit_pending_closure.sql (1.18ms)11312026/09/21 18:17:18 OK 2_object_stats_trigger.sql (393.88µs)11322026/09/21 18:17:18 goose: up to current file version: 211332026-09-21 18:17:19.052 UTC [9573] ERROR: relation "goose_db_version" does not exist at character 3611342026-09-21 18:17:19.052 UTC [9573] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1135--- PASS: TestReadProxyInvalidPath (1.05s)1136=== CONT TestObjectStatsTrigger11372026/09/21 18:17:19 OK 20241026095416_initial_model.sql (40.87ms)11382026/09/21 18:17:19 OK 20251210153512_drop_unused_gin_index.sql (10.53ms)11392026/09/21 18:17:19 OK 20251218171726_add_pins.sql (2.31ms)11402026/09/21 18:17:19 OK 20260628120000_add_object_size_and_stats.sql (33.14ms)11412026/09/21 18:17:19 OK 20260905000000_add_claims.sql (19.75ms)11422026/09/21 18:17:19 OK 20260920000000_drop_claims.sql (14.26ms)11432026/09/21 18:17:19 goose: successfully migrated database to version: 2026092000000011442026/09/21 18:17:19 OK 1_commit_pending_closure.sql (2.22ms)11452026/09/21 18:17:19 OK 2_object_stats_trigger.sql (407.96µs)11462026/09/21 18:17:19 goose: up to current file version: 21147--- PASS: TestReadProxy404 (1.11s)1148=== CONT TestMultipartCleanup11492026-09-21 18:17:19.315 UTC [9578] ERROR: relation "goose_db_version" does not exist at character 3611502026-09-21 18:17:19.315 UTC [9578] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026/09/21 18:17:19 OK 20241026095416_initial_model.sql (89.98ms)11522026/09/21 18:17:19 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)1153--- PASS: TestReadProxyNarStreaming (1.13s)1154=== CONT TestServerTLSConfig1155=== RUN TestServerTLSConfig/no_client_CA1156=== PAUSE TestServerTLSConfig/no_client_CA1157=== RUN TestServerTLSConfig/missing_CA_file1158=== PAUSE TestServerTLSConfig/missing_CA_file1159=== RUN TestServerTLSConfig/not_a_PEM_file1160=== PAUSE TestServerTLSConfig/not_a_PEM_file1161=== CONT TestService_NativeMTLS11622026/09/21 18:17:19 OK 20251218171726_add_pins.sql (16.58ms)11632026/09/21 18:17:19 OK 20260628120000_add_object_size_and_stats.sql (16.99ms)11642026-09-21 18:17:19.495 UTC [9581] ERROR: relation "goose_db_version" does not exist at character 3611652026-09-21 18:17:19.495 UTC [9581] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/09/21 18:17:19 OK 20260905000000_add_claims.sql (23.16ms)11672026/09/21 18:17:19 OK 20260920000000_drop_claims.sql (15.74ms)11682026/09/21 18:17:19 goose: successfully migrated database to version: 2026092000000011692026/09/21 18:17:19 OK 1_commit_pending_closure.sql (2.01ms)11702026/09/21 18:17:19 OK 2_object_stats_trigger.sql (410.54µs)11712026/09/21 18:17:19 goose: up to current file version: 211722026-09-21 18:17:19.569 UTC [9582] ERROR: relation "goose_db_version" does not exist at character 3611732026-09-21 18:17:19.569 UTC [9582] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11742026/09/21 18:17:19 OK 20241026095416_initial_model.sql (79.31ms)11752026/09/21 18:17:19 OK 20251210153512_drop_unused_gin_index.sql (3.85ms)1176--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.17s)1177=== CONT TestMetricsInventory11782026/09/21 18:17:19 OK 20251218171726_add_pins.sql (23.55ms)11792026/09/21 18:17:19 OK 20260628120000_add_object_size_and_stats.sql (8.99ms)11802026/09/21 18:17:19 OK 20241026095416_initial_model.sql (61.99ms)11812026/09/21 18:17:19 OK 20251210153512_drop_unused_gin_index.sql (7.43ms)11822026/09/21 18:17:19 OK 20260905000000_add_claims.sql (31.04ms)11832026-09-21 18:17:19.677 UTC [9585] ERROR: relation "goose_db_version" does not exist at character 3611842026-09-21 18:17:19.677 UTC [9585] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/09/21 18:17:19 OK 20251218171726_add_pins.sql (4.88ms)11862026/09/21 18:17:19 OK 20260920000000_drop_claims.sql (14.84ms)11872026/09/21 18:17:19 goose: successfully migrated database to version: 2026092000000011882026/09/21 18:17:19 OK 1_commit_pending_closure.sql (2.19ms)11892026/09/21 18:17:19 OK 2_object_stats_trigger.sql (398.46µs)11902026/09/21 18:17:19 goose: up to current file version: 211912026/09/21 18:17:19 OK 20260628120000_add_object_size_and_stats.sql (22.16ms)11922026/09/21 18:17:19 OK 20260905000000_add_claims.sql (20.63ms)11932026/09/21 18:17:19 OK 20260920000000_drop_claims.sql (25.88ms)11942026/09/21 18:17:19 goose: successfully migrated database to version: 2026092000000011952026/09/21 18:17:19 OK 1_commit_pending_closure.sql (42.39ms)11962026/09/21 18:17:19 OK 2_object_stats_trigger.sql (2.26ms)11972026/09/21 18:17:19 goose: up to current file version: 21198--- PASS: TestReadProxyNarinfo (1.18s)1199=== CONT TestNARDeduplicationMetadataUploadBug12002026/09/21 18:17:19 OK 20241026095416_initial_model.sql (105.07ms)12012026/09/21 18:17:19 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)12022026/09/21 18:17:19 OK 20251218171726_add_pins.sql (15.71ms)12032026/09/21 18:17:19 OK 20260628120000_add_object_size_and_stats.sql (11.58ms)12042026/09/21 18:17:19 OK 20260905000000_add_claims.sql (21.93ms)12052026/09/21 18:17:19 OK 20260920000000_drop_claims.sql (10.02ms)12062026/09/21 18:17:19 goose: successfully migrated database to version: 2026092000000012072026/09/21 18:17:19 OK 1_commit_pending_closure.sql (2.33ms)12082026/09/21 18:17:19 OK 2_object_stats_trigger.sql (500.96µs)12092026/09/21 18:17:19 goose: up to current file version: 212102026-09-21 18:17:19.911 UTC [9588] ERROR: relation "goose_db_version" does not exist at character 3612112026-09-21 18:17:19.911 UTC [9588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12122026/09/21 18:17:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12132026/09/21 18:17:19 WARN Refused reserved pin name=worker-x86_64-linux12142026/09/21 18:17:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12152026/09/21 18:17:19 INFO Received create pin request method=POST path=/api/pins/my-app12162026/09/21 18:17:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1217--- PASS: TestCreatePin_ReservedPins (1.29s)1218=== CONT TestCreatePendingClosureRejectsOversizedNAR12192026/09/21 18:17:19 INFO Received uploads request method=POST path=/api/pending_closures1220--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1221=== CONT TestCacheConfigHandlerMaxNarSize1222--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1223=== CONT TestGenerateLandingPage1224--- PASS: TestGenerateLandingPage (0.00s)1225=== CONT TestService_readinessHandler12262026/09/21 18:17:20 OK 20241026095416_initial_model.sql (44.75ms)12272026/09/21 18:17:20 OK 20251210153512_drop_unused_gin_index.sql (8.77ms)12282026/09/21 18:17:20 OK 20251218171726_add_pins.sql (7.79ms)12292026/09/21 18:17:20 OK 20260628120000_add_object_size_and_stats.sql (17.25ms)12302026/09/21 18:17:20 OK 20260905000000_add_claims.sql (23.14ms)12312026/09/21 18:17:20 OK 20260920000000_drop_claims.sql (15.07ms)12322026/09/21 18:17:20 goose: successfully migrated database to version: 2026092000000012332026/09/21 18:17:20 OK 1_commit_pending_closure.sql (1.86ms)12342026/09/21 18:17:20 OK 2_object_stats_trigger.sql (372.83µs)12352026/09/21 18:17:20 goose: up to current file version: 212362026-09-21 18:17:20.101 UTC [9592] ERROR: relation "goose_db_version" does not exist at character 3612372026-09-21 18:17:20.101 UTC [9592] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1238--- PASS: TestResurrectedObjectNotDeleted (1.41s)1239=== CONT TestService_healthCheckHandler12402026/09/21 18:17:20 OK 20241026095416_initial_model.sql (65.32ms)12412026/09/21 18:17:20 OK 20251210153512_drop_unused_gin_index.sql (4.69ms)12422026/09/21 18:17:20 OK 20251218171726_add_pins.sql (8.42ms)12432026/09/21 18:17:20 OK 20260628120000_add_object_size_and_stats.sql (16.05ms)12442026-09-21 18:17:20.230 UTC [9595] ERROR: relation "goose_db_version" does not exist at character 3612452026-09-21 18:17:20.230 UTC [9595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026/09/21 18:17:20 OK 20260905000000_add_claims.sql (37.45ms)12472026/09/21 18:17:20 OK 20260920000000_drop_claims.sql (20.86ms)12482026/09/21 18:17:20 goose: successfully migrated database to version: 2026092000000012492026/09/21 18:17:20 OK 1_commit_pending_closure.sql (3.22ms)12502026/09/21 18:17:20 OK 2_object_stats_trigger.sql (648.08µs)12512026/09/21 18:17:20 goose: up to current file version: 212522026-09-21 18:17:20.346 UTC [9596] ERROR: relation "goose_db_version" does not exist at character 3612532026-09-21 18:17:20.346 UTC [9596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026/09/21 18:17:20 OK 20241026095416_initial_model.sql (79.62ms)12552026/09/21 18:17:20 OK 20251210153512_drop_unused_gin_index.sql (11.13ms)12562026/09/21 18:17:20 OK 20251218171726_add_pins.sql (17.93ms)12572026/09/21 18:17:20 OK 20260628120000_add_object_size_and_stats.sql (15.92ms)12582026/09/21 18:17:20 OK 20260905000000_add_claims.sql (35.49ms)12592026/09/21 18:17:20 OK 20260920000000_drop_claims.sql (22.33ms)12602026/09/21 18:17:20 goose: successfully migrated database to version: 2026092000000012612026/09/21 18:17:20 OK 1_commit_pending_closure.sql (3.69ms)12622026/09/21 18:17:20 OK 2_object_stats_trigger.sql (810.04µs)12632026/09/21 18:17:20 goose: up to current file version: 212642026/09/21 18:17:20 OK 20241026095416_initial_model.sql (89.09ms)12652026/09/21 18:17:20 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)12662026/09/21 18:17:20 OK 20251218171726_add_pins.sql (5.91ms)12672026-09-21 18:17:20.500 UTC [9597] ERROR: relation "goose_db_version" does not exist at character 3612682026-09-21 18:17:20.500 UTC [9597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12692026/09/21 18:17:20 OK 20260628120000_add_object_size_and_stats.sql (25.83ms)12702026/09/21 18:17:20 OK 20260905000000_add_claims.sql (5.61ms)12712026/09/21 18:17:20 OK 20260920000000_drop_claims.sql (9.7ms)12722026/09/21 18:17:20 goose: successfully migrated database to version: 2026092000000012732026/09/21 18:17:20 OK 1_commit_pending_closure.sql (2.15ms)12742026/09/21 18:17:20 OK 2_object_stats_trigger.sql (580.75µs)12752026/09/21 18:17:20 goose: up to current file version: 212762026/09/21 18:17:20 OK 20241026095416_initial_model.sql (55.6ms)12772026/09/21 18:17:20 OK 20251210153512_drop_unused_gin_index.sql (7.35ms)12782026/09/21 18:17:20 OK 20251218171726_add_pins.sql (23.95ms)12792026/09/21 18:17:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2094 objects_failed=01280=== NAME TestClientIntegration1281 client_integration_test.go:323: Objects in database after GC:1282 client_integration_test.go:323: Successfully deleted all objects with GC --force12832026/09/21 18:17:20 OK 20260628120000_add_object_size_and_stats.sql (37.26ms)1284--- PASS: TestClientIntegration (3.83s)1285=== CONT TestGracefulShutdownDrainsInflight12862026/09/21 18:17:20 INFO Starting HTTP server address=127.0.0.1:5130712872026/09/21 18:17:20 INFO Shutdown signal received, draining in-flight requests timeout=10s12882026/09/21 18:17:20 OK 20260905000000_add_claims.sql (8.99ms)12892026/09/21 18:17:20 OK 20260920000000_drop_claims.sql (5.06ms)12902026/09/21 18:17:20 goose: successfully migrated database to version: 2026092000000012912026/09/21 18:17:20 OK 1_commit_pending_closure.sql (2.61ms)12922026/09/21 18:17:20 OK 2_object_stats_trigger.sql (638.54µs)12932026/09/21 18:17:20 goose: up to current file version: 21294--- PASS: TestObjectStatsTrigger (1.57s)1295=== CONT TestService_AuthMiddleware_OIDC12962026-09-21 18:17:20.680 UTC [9598] ERROR: relation "goose_db_version" does not exist at character 3612972026-09-21 18:17:20.680 UTC [9598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12982026/09/21 18:17:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51309/oidc1299--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1300=== CONT TestService_ReadScope_PublicByDefault13012026/09/21 18:17:20 OK 20241026095416_initial_model.sql (48.29ms)13022026/09/21 18:17:20 OK 20251210153512_drop_unused_gin_index.sql (5.89ms)13032026/09/21 18:17:20 OK 20251218171726_add_pins.sql (7.15ms)13042026/09/21 18:17:20 OK 20260628120000_add_object_size_and_stats.sql (23.72ms)13052026-09-21 18:17:20.784 UTC [9603] ERROR: relation "goose_db_version" does not exist at character 3613062026-09-21 18:17:20.784 UTC [9603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13072026/09/21 18:17:20 INFO Received uploads request method=POST path=/api/pending_closures13082026/09/21 18:17:20 OK 20260905000000_add_claims.sql (25.31ms)13092026/09/21 18:17:20 OK 20260920000000_drop_claims.sql (2ms)13102026/09/21 18:17:20 goose: successfully migrated database to version: 2026092000000013112026/09/21 18:17:20 OK 1_commit_pending_closure.sql (2.61ms)13122026/09/21 18:17:20 OK 2_object_stats_trigger.sql (372.88µs)13132026/09/21 18:17:20 goose: up to current file version: 213142026/09/21 18:17:20 OK 20241026095416_initial_model.sql (69.45ms)13152026/09/21 18:17:20 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)13162026/09/21 18:17:20 OK 20251218171726_add_pins.sql (15.01ms)1317=== NAME TestOrphanedObjectsGC1318 orphaned_objects_gc_test.go:290: GC Test Summary:1319 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1320 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1321 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1322 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1323 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1324--- PASS: TestOrphanedObjectsGC (1.93s)1325=== CONT TestService_RequireScope_OIDC13262026/09/21 18:17:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51312/oidc13272026/09/21 18:17:20 OK 20260628120000_add_object_size_and_stats.sql (19.49ms)13282026/09/21 18:17:20 OK 20260905000000_add_claims.sql (25.17ms)13292026/09/21 18:17:20 INFO Received cleanup request method=DELETE path=/api/pending_closures13302026/09/21 18:17:20 INFO Aborted multipart uploads count=11331--- PASS: TestMultipartCleanup (1.69s)1332=== CONT TestService_cleanupPendingClosuresHandler13332026/09/21 18:17:20 OK 20260920000000_drop_claims.sql (29.14ms)13342026/09/21 18:17:20 goose: successfully migrated database to version: 2026092000000013352026/09/21 18:17:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13362026/09/21 18:17:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1337--- PASS: TestService_NativeMTLS (1.53s)1338=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13392026/09/21 18:17:20 OK 1_commit_pending_closure.sql (3.18ms)13402026/09/21 18:17:20 OK 2_object_stats_trigger.sql (772.96µs)13412026/09/21 18:17:20 goose: up to current file version: 213422026-09-21 18:17:20.989 UTC [9609] ERROR: relation "goose_db_version" does not exist at character 3613432026-09-21 18:17:20.989 UTC [9609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13442026/09/21 18:17:21 OK 20241026095416_initial_model.sql (51.71ms)13452026/09/21 18:17:21 OK 20251210153512_drop_unused_gin_index.sql (5.93ms)13462026/09/21 18:17:21 OK 20251218171726_add_pins.sql (44.16ms)13472026/09/21 18:17:21 OK 20260628120000_add_object_size_and_stats.sql (19.23ms)13482026/09/21 18:17:21 OK 20260905000000_add_claims.sql (18.91ms)1349--- PASS: TestMetricsInventory (1.55s)1350=== CONT TestCompleteMultipartUnregistered13512026/09/21 18:17:21 OK 20260920000000_drop_claims.sql (17.61ms)13522026/09/21 18:17:21 goose: successfully migrated database to version: 2026092000000013532026/09/21 18:17:21 OK 1_commit_pending_closure.sql (5.41ms)13542026/09/21 18:17:21 OK 2_object_stats_trigger.sql (674.58µs)13552026/09/21 18:17:21 goose: up to current file version: 21356=== NAME TestNARDeduplicationMetadataUploadBug1357 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-9315-1570051187/TestNARDeduplicationMetadataUploadBug3504645368/001/store/vsxkbjaankm7knf0kddidpbik8pvi1zp-file1.txt13582026/09/21 18:17:21 WARN readiness check failed error="closed pool"1359--- PASS: TestService_readinessHandler (1.46s)1360=== CONT TestService_verifyS3Integrity13612026-09-21 18:17:21.493 UTC [9620] ERROR: relation "goose_db_version" does not exist at character 3613622026-09-21 18:17:21.493 UTC [9620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/09/21 18:17:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13642026-09-21 18:17:21.523 UTC [9623] ERROR: relation "goose_db_version" does not exist at character 3613652026-09-21 18:17:21.523 UTC [9623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13662026/09/21 18:17:21 INFO Received uploads request method=POST path=/api/pending_closures13672026/09/21 18:17:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13682026/09/21 18:17:21 INFO Uploading vsxkbjaankm7knf0kddidpbik8pvi1zp-file1.txt (160B)13692026/09/21 18:17:21 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13702026/09/21 18:17:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13712026/09/21 18:17:21 INFO Signed narinfos id=1 count=113722026/09/21 18:17:21 INFO Uploading 1 narinfos13732026/09/21 18:17:21 WARN Failed to register uploaded object key=vsxkbjaankm7knf0kddidpbik8pvi1zp.ls error="server returned 404: 404 page not found\n"13742026/09/21 18:17:21 OK 20241026095416_initial_model.sql (59.95ms)13752026/09/21 18:17:21 OK 20251210153512_drop_unused_gin_index.sql (13.44ms)13762026/09/21 18:17:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13772026/09/21 18:17:21 WARN Failed to register uploaded object key=vsxkbjaankm7knf0kddidpbik8pvi1zp.narinfo error="server returned 404: 404 page not found\n"13782026/09/21 18:17:21 OK 20251218171726_add_pins.sql (18.74ms)1379--- PASS: TestService_healthCheckHandler (1.43s)1380=== CONT TestService_createPendingClosureHandler13812026/09/21 18:17:21 INFO Completed upload id=113822026/09/21 18:17:21 INFO Upload complete. (170ms)13832026/09/21 18:17:21 OK 20260628120000_add_object_size_and_stats.sql (8.75ms)1384=== NAME TestNARDeduplicationMetadataUploadBug1385 metadata_upload_test.go:54: Retrieved narinfo from S3:1386 StorePath: /nix/var/nix/builds/nix-9315-1570051187/TestNARDeduplicationMetadataUploadBug3504645368/001/store/vsxkbjaankm7knf0kddidpbik8pvi1zp-file1.txt1387 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1388 Compression: zstd1389 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1390 NarSize: 1601391 References: 1392 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1393 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1394 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1395 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13962026/09/21 18:17:21 OK 20260905000000_add_claims.sql (1.46ms)13972026/09/21 18:17:21 OK 20260920000000_drop_claims.sql (1.59ms)13982026/09/21 18:17:21 goose: successfully migrated database to version: 2026092000000013992026/09/21 18:17:21 OK 1_commit_pending_closure.sql (1.34ms)14002026/09/21 18:17:21 OK 2_object_stats_trigger.sql (357.33µs)14012026/09/21 18:17:21 goose: up to current file version: 214022026/09/21 18:17:21 OK 20241026095416_initial_model.sql (94.85ms)14032026-09-21 18:17:21.649 UTC [9628] ERROR: relation "goose_db_version" does not exist at character 3614042026-09-21 18:17:21.649 UTC [9628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14052026/09/21 18:17:21 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)14062026/09/21 18:17:21 OK 20251218171726_add_pins.sql (19.16ms)1407 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-9315-1570051187/TestNARDeduplicationMetadataUploadBug3504645368/001/store/rh9hx7rj73qsckrmg7grd0wbgjjh2ip0-file2.txt14082026/09/21 18:17:21 OK 20260628120000_add_object_size_and_stats.sql (12.49ms)14092026-09-21 18:17:21.701 UTC [9631] ERROR: relation "goose_db_version" does not exist at character 3614102026-09-21 18:17:21.701 UTC [9631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14112026/09/21 18:17:21 OK 20260905000000_add_claims.sql (20.09ms)14122026/09/21 18:17:21 OK 20260920000000_drop_claims.sql (11.54ms)14132026/09/21 18:17:21 goose: successfully migrated database to version: 2026092000000014142026/09/21 18:17:21 OK 1_commit_pending_closure.sql (1.88ms)14152026/09/21 18:17:21 OK 20241026095416_initial_model.sql (44.14ms)14162026/09/21 18:17:21 OK 2_object_stats_trigger.sql (319.25µs)14172026/09/21 18:17:21 goose: up to current file version: 214182026/09/21 18:17:21 OK 20251210153512_drop_unused_gin_index.sql (6.32ms)14192026/09/21 18:17:21 OK 20251218171726_add_pins.sql (10.02ms)14202026/09/21 18:17:21 OK 20260628120000_add_object_size_and_stats.sql (23.05ms)14212026/09/21 18:17:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14222026/09/21 18:17:21 OK 20260905000000_add_claims.sql (21.21ms)14232026/09/21 18:17:21 OK 20260920000000_drop_claims.sql (13.14ms)14242026/09/21 18:17:21 goose: successfully migrated database to version: 2026092000000014252026/09/21 18:17:21 OK 20241026095416_initial_model.sql (66.37ms)14262026/09/21 18:17:21 OK 1_commit_pending_closure.sql (886.04µs)14272026/09/21 18:17:21 OK 2_object_stats_trigger.sql (258.96µs)14282026/09/21 18:17:21 goose: up to current file version: 214292026/09/21 18:17:21 INFO Received uploads request method=POST path=/api/pending_closures14302026/09/21 18:17:21 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14312026/09/21 18:17:21 OK 20251210153512_drop_unused_gin_index.sql (14.85ms)1432=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1433=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1434=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1435=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1436=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1437=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1438=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1439=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1440=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14412026/09/21 18:17:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14422026/09/21 18:17:21 INFO Signed narinfos id=2 count=114432026/09/21 18:17:21 WARN Failed to register uploaded object key=rh9hx7rj73qsckrmg7grd0wbgjjh2ip0.ls error="server returned 404: 404 page not found\n"14442026/09/21 18:17:21 INFO Uploading 1 narinfos14452026/09/21 18:17:21 OK 20251218171726_add_pins.sql (3.35ms)14462026/09/21 18:17:21 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14472026/09/21 18:17:21 WARN Failed to register uploaded object key=rh9hx7rj73qsckrmg7grd0wbgjjh2ip0.narinfo error="server returned 404: 404 page not found\n"14482026/09/21 18:17:21 INFO Completed upload id=214492026/09/21 18:17:21 INFO Upload complete. (113ms)1450=== NAME TestNARDeduplicationMetadataUploadBug1451 metadata_upload_test.go:76: Retrieved narinfo from S3:1452 StorePath: /nix/var/nix/builds/nix-9315-1570051187/TestNARDeduplicationMetadataUploadBug3504645368/001/store/rh9hx7rj73qsckrmg7grd0wbgjjh2ip0-file2.txt1453 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1454 Compression: zstd1455 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1456 NarSize: 1601457 References: 1458 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1459 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1460 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1461 {"version":1,"root":{"type":"regular","size":44}}14622026/09/21 18:17:21 OK 20260628120000_add_object_size_and_stats.sql (18.64ms)14632026/09/21 18:17:21 OK 20260905000000_add_claims.sql (15.16ms)14642026-09-21 18:17:21.842 UTC [9639] ERROR: relation "goose_db_version" does not exist at character 3614652026-09-21 18:17:21.842 UTC [9639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1466--- PASS: TestNARDeduplicationMetadataUploadBug (2.04s)1467=== CONT TestService_ReadAuthMiddleware14682026/09/21 18:17:21 OK 20260920000000_drop_claims.sql (8.57ms)14692026/09/21 18:17:21 goose: successfully migrated database to version: 2026092000000014702026/09/21 18:17:21 OK 1_commit_pending_closure.sql (981.13µs)14712026/09/21 18:17:21 OK 2_object_stats_trigger.sql (243.54µs)14722026/09/21 18:17:21 goose: up to current file version: 214732026/09/21 18:17:21 OK 20241026095416_initial_model.sql (39.86ms)14742026/09/21 18:17:21 OK 20251210153512_drop_unused_gin_index.sql (6.83ms)14752026/09/21 18:17:21 OK 20251218171726_add_pins.sql (19.77ms)14762026/09/21 18:17:21 OK 20260628120000_add_object_size_and_stats.sql (23.17ms)1477--- PASS: TestService_ReadScope_PublicByDefault (1.25s)1478=== CONT TestService_AuthMiddleware_MTLSProxyHeader14792026/09/21 18:17:21 OK 20260905000000_add_claims.sql (16.67ms)14802026/09/21 18:17:21 OK 20260920000000_drop_claims.sql (1.41ms)14812026/09/21 18:17:21 goose: successfully migrated database to version: 2026092000000014822026/09/21 18:17:21 OK 1_commit_pending_closure.sql (1.17ms)14832026/09/21 18:17:21 OK 2_object_stats_trigger.sql (266.71µs)14842026/09/21 18:17:21 goose: up to current file version: 214852026-09-21 18:17:21.997 UTC [9643] ERROR: relation "goose_db_version" does not exist at character 3614862026-09-21 18:17:21.997 UTC [9643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14872026/09/21 18:17:22 OK 20241026095416_initial_model.sql (48.25ms)14882026/09/21 18:17:22 OK 20251210153512_drop_unused_gin_index.sql (6.44ms)14892026/09/21 18:17:22 OK 20251218171726_add_pins.sql (25.5ms)14902026/09/21 18:17:22 OK 20260628120000_add_object_size_and_stats.sql (25.51ms)14912026/09/21 18:17:22 OK 20260905000000_add_claims.sql (13.04ms)1492=== RUN TestService_RequireScope_OIDC/builder_may_write1493=== PAUSE TestService_RequireScope_OIDC/builder_may_write1494=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1495=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1496=== RUN TestService_RequireScope_OIDC/ops_may_admin1497=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1498=== RUN TestService_RequireScope_OIDC/ops_may_not_write1499=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1500=== RUN TestService_RequireScope_OIDC/reader_may_not_write1501=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1502=== RUN TestService_RequireScope_OIDC/static_token_may_admin1503=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1504=== RUN TestService_RequireScope_OIDC/static_token_may_write1505=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1506=== RUN TestService_RequireScope_OIDC/reader_may_read1507=== PAUSE TestService_RequireScope_OIDC/reader_may_read1508=== RUN TestService_RequireScope_OIDC/writer_implies_read1509=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1510=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1511=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1512=== CONT TestClientErrorHandling1513=== RUN TestClientErrorHandling/InvalidStorePath1514=== PAUSE TestClientErrorHandling/InvalidStorePath1515=== RUN TestClientErrorHandling/InvalidAuthToken1516=== PAUSE TestClientErrorHandling/InvalidAuthToken1517=== RUN TestClientErrorHandling/ServerNotAvailable1518=== PAUSE TestClientErrorHandling/ServerNotAvailable1519=== CONT TestUploadHandlersRejectInvalidKeys1520=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1521=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1522=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1523=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1524=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1525=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1526=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1527=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1528=== CONT TestUploadHandlersRejectOversizedBody15292026/09/21 18:17:22 OK 20260920000000_drop_claims.sql (16.33ms)15302026/09/21 18:17:22 goose: successfully migrated database to version: 2026092000000015312026/09/21 18:17:22 OK 1_commit_pending_closure.sql (16.47ms)1532=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1533=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1534=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1535=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1536=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1537=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1538=== CONT TestPinProtectsFromGC15392026/09/21 18:17:22 OK 2_object_stats_trigger.sql (1.22ms)15402026/09/21 18:17:22 goose: up to current file version: 215412026/09/21 18:17:22 INFO Received cleanup request method=DELETE path=/api/pending_closures15422026/09/21 18:17:22 INFO Aborted multipart uploads count=015432026/09/21 18:17:22 INFO Received uploads request method=POST path=/api/pending_closures15442026-09-21 18:17:22.337 UTC [9647] ERROR: relation "goose_db_version" does not exist at character 3615452026-09-21 18:17:22.337 UTC [9647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15462026/09/21 18:17:22 INFO Received cleanup request method=DELETE path=/api/pending_closures15472026/09/21 18:17:22 INFO Aborted multipart uploads count=115482026/09/21 18:17:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15492026-09-21 18:17:22.358 UTC [9631] ERROR: Closure does not exist: id=115502026-09-21 18:17:22.358 UTC [9631] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE15512026-09-21 18:17:22.358 UTC [9631] STATEMENT: -- name: CommitPendingClosure :exec1552 SELECT commit_pending_closure($1::bigint)1553 1554--- PASS: TestService_cleanupPendingClosuresHandler (1.40s)1555=== CONT TestCompletedNarNotReofferedAcrossClosures15562026/09/21 18:17:22 OK 20241026095416_initial_model.sql (100.24ms)15572026/09/21 18:17:22 OK 20251210153512_drop_unused_gin_index.sql (8.36ms)15582026/09/21 18:17:22 INFO Received uploads request method=POST path=/api/pending_closures15592026-09-21 18:17:22.488 UTC [9650] ERROR: relation "goose_db_version" does not exist at character 3615602026-09-21 18:17:22.488 UTC [9650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15612026/09/21 18:17:22 OK 20251218171726_add_pins.sql (12.53ms)15622026/09/21 18:17:22 OK 20260628120000_add_object_size_and_stats.sql (10.2ms)1563--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.56s)1564=== CONT TestSkippedUploadsHandler15652026/09/21 18:17:22 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001566--- PASS: TestSkippedUploadsHandler (0.00s)1567=== CONT TestParseSize1568--- PASS: TestParseSize (0.00s)1569=== CONT TestService_Rustfstest15702026/09/21 18:17:22 OK 20260905000000_add_claims.sql (40.28ms)15712026/09/21 18:17:22 OK 20260920000000_drop_claims.sql (37.91ms)15722026/09/21 18:17:22 goose: successfully migrated database to version: 2026092000000015732026/09/21 18:17:22 OK 1_commit_pending_closure.sql (2.26ms)15742026/09/21 18:17:22 OK 2_object_stats_trigger.sql (491.5µs)15752026/09/21 18:17:22 goose: up to current file version: 215762026/09/21 18:17:22 OK 20241026095416_initial_model.sql (177.01ms)15772026/09/21 18:17:22 OK 20251210153512_drop_unused_gin_index.sql (16.2ms)15782026/09/21 18:17:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15792026/09/21 18:17:22 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1580--- PASS: TestCompleteMultipartUnregistered (1.59s)1581=== CONT TestPresignedUploadRegisteredBeforeCommit15822026/09/21 18:17:22 OK 20251218171726_add_pins.sql (31.95ms)15832026/09/21 18:17:22 OK 20260628120000_add_object_size_and_stats.sql (44.45ms)15842026/09/21 18:17:22 OK 20260905000000_add_claims.sql (37.05ms)15852026/09/21 18:17:22 OK 20260920000000_drop_claims.sql (36.24ms)15862026/09/21 18:17:22 goose: successfully migrated database to version: 2026092000000015872026/09/21 18:17:22 OK 1_commit_pending_closure.sql (3.36ms)15882026/09/21 18:17:22 OK 2_object_stats_trigger.sql (711.38µs)15892026/09/21 18:17:22 goose: up to current file version: 215902026/09/21 18:17:23 INFO Received uploads request method=POST path=/api/pending_closures15912026-09-21 18:17:23.400 UTC [9655] ERROR: relation "goose_db_version" does not exist at character 3615922026-09-21 18:17:23.400 UTC [9655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15932026-09-21 18:17:23.409 UTC [9656] ERROR: relation "goose_db_version" does not exist at character 3615942026-09-21 18:17:23.409 UTC [9656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15952026/09/21 18:17:23 INFO Received uploads request method=POST path=/api/pending_closures15962026/09/21 18:17:23 INFO Received uploads request method=POST path=/api/pending_closures15972026/09/21 18:17:23 INFO Received uploads request method=POST path=/api/pending_closures15982026/09/21 18:17:23 OK 20241026095416_initial_model.sql (202.02ms)15992026/09/21 18:17:23 OK 20251210153512_drop_unused_gin_index.sql (8.46ms)16002026/09/21 18:17:23 OK 20241026095416_initial_model.sql (215.27ms)16012026/09/21 18:17:23 OK 20251210153512_drop_unused_gin_index.sql (5.99ms)16022026/09/21 18:17:23 OK 20251218171726_add_pins.sql (38.82ms)16032026/09/21 18:17:23 OK 20251218171726_add_pins.sql (22.73ms)16042026/09/21 18:17:23 OK 20260628120000_add_object_size_and_stats.sql (34.8ms)16052026/09/21 18:17:23 OK 20260628120000_add_object_size_and_stats.sql (42.41ms)1606=== NAME TestOrphanedObjectsGCStressTest1607 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16082026-09-21 18:17:23.838 UTC [9657] ERROR: relation "goose_db_version" does not exist at character 3616092026-09-21 18:17:23.838 UTC [9657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16102026/09/21 18:17:23 OK 20260905000000_add_claims.sql (84.84ms)16112026/09/21 18:17:23 OK 20260905000000_add_claims.sql (74.56ms)16122026/09/21 18:17:23 OK 20260920000000_drop_claims.sql (24.73ms)16132026/09/21 18:17:23 goose: successfully migrated database to version: 2026092000000016142026/09/21 18:17:23 OK 1_commit_pending_closure.sql (2.28ms)16152026/09/21 18:17:23 OK 2_object_stats_trigger.sql (468.33µs)16162026/09/21 18:17:23 goose: up to current file version: 216172026/09/21 18:17:23 OK 20260920000000_drop_claims.sql (22.13ms)16182026/09/21 18:17:23 goose: successfully migrated database to version: 2026092000000016192026/09/21 18:17:23 OK 1_commit_pending_closure.sql (1.9ms)16202026/09/21 18:17:23 OK 2_object_stats_trigger.sql (420.79µs)16212026/09/21 18:17:23 goose: up to current file version: 21622 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16232026/09/21 18:17:24 OK 20241026095416_initial_model.sql (237.37ms)16242026/09/21 18:17:24 OK 20251210153512_drop_unused_gin_index.sql (22.38ms)16252026/09/21 18:17:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16262026/09/21 18:17:24 WARN mTLS auth: bound subjects configured but subject DN unavailable16272026/09/21 18:17:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1628--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.41s)1629=== CONT TestIsValidUploadKey1630=== RUN TestIsValidUploadKey/narinfo1631=== PAUSE TestIsValidUploadKey/narinfo1632=== RUN TestIsValidUploadKey/nar_zst1633=== PAUSE TestIsValidUploadKey/nar_zst1634=== RUN TestIsValidUploadKey/nar_xz1635=== PAUSE TestIsValidUploadKey/nar_xz1636=== RUN TestIsValidUploadKey/nar_plain1637=== PAUSE TestIsValidUploadKey/nar_plain1638=== RUN TestIsValidUploadKey/listing1639=== PAUSE TestIsValidUploadKey/listing1640=== RUN TestIsValidUploadKey/build_log1641=== PAUSE TestIsValidUploadKey/build_log1642=== RUN TestIsValidUploadKey/build_log_home-manager_file1643=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1644=== RUN TestIsValidUploadKey/build_log_plus_in_name1645=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1646=== RUN TestIsValidUploadKey/build_log_question_mark1647=== PAUSE TestIsValidUploadKey/build_log_question_mark1648=== RUN TestIsValidUploadKey/build_log_equals1649=== PAUSE TestIsValidUploadKey/build_log_equals1650=== RUN TestIsValidUploadKey/realisation1651=== PAUSE TestIsValidUploadKey/realisation1652=== RUN TestIsValidUploadKey/realisation_plus_in_output1653=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1654=== RUN TestIsValidUploadKey/nix-cache-info1655=== PAUSE TestIsValidUploadKey/nix-cache-info1656=== RUN TestIsValidUploadKey/index.html1657=== PAUSE TestIsValidUploadKey/index.html1658=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1659=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1660=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1661=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1662=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1663=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1664=== RUN TestIsValidUploadKey/traversal1665=== PAUSE TestIsValidUploadKey/traversal1666=== RUN TestIsValidUploadKey/traversal_nar1667=== PAUSE TestIsValidUploadKey/traversal_nar1668=== RUN TestIsValidUploadKey/absolute1669=== PAUSE TestIsValidUploadKey/absolute1670=== RUN TestIsValidUploadKey/empty_key1671=== PAUSE TestIsValidUploadKey/empty_key1672=== RUN TestIsValidUploadKey/unknown_type1673=== PAUSE TestIsValidUploadKey/unknown_type1674=== CONT TestReadRedirectUsesPublicS3URL16752026-09-21 18:17:24.226 UTC [9658] ERROR: relation "goose_db_version" does not exist at character 3616762026-09-21 18:17:24.226 UTC [9658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16772026/09/21 18:17:24 OK 20251218171726_add_pins.sql (37.94ms)16782026/09/21 18:17:24 OK 20260628120000_add_object_size_and_stats.sql (42.27ms)16792026/09/21 18:17:24 OK 20260905000000_add_claims.sql (57.58ms)16802026/09/21 18:17:24 OK 20260920000000_drop_claims.sql (55.95ms)16812026/09/21 18:17:24 goose: successfully migrated database to version: 2026092000000016822026/09/21 18:17:24 OK 1_commit_pending_closure.sql (3.17ms)16832026/09/21 18:17:24 OK 2_object_stats_trigger.sql (1.05ms)16842026/09/21 18:17:24 goose: up to current file version: 216852026/09/21 18:17:24 OK 20241026095416_initial_model.sql (246.04ms)16862026/09/21 18:17:24 OK 20251210153512_drop_unused_gin_index.sql (16.92ms)1687--- PASS: TestService_ReadAuthMiddleware (2.72s)1688=== CONT TestCompleteMultipartUpload_ErrorButObjectExists16892026/09/21 18:17:24 OK 20251218171726_add_pins.sql (37.16ms)16902026/09/21 18:17:24 OK 20260628120000_add_object_size_and_stats.sql (52.82ms)16912026/09/21 18:17:24 OK 20260905000000_add_claims.sql (54.46ms)16922026/09/21 18:17:24 OK 20260920000000_drop_claims.sql (47.16ms)16932026/09/21 18:17:24 goose: successfully migrated database to version: 2026092000000016942026/09/21 18:17:24 OK 1_commit_pending_closure.sql (3.09ms)16952026/09/21 18:17:24 OK 2_object_stats_trigger.sql (596.92µs)16962026/09/21 18:17:24 goose: up to current file version: 216972026/09/21 18:17:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16982026/09/21 18:17:24 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmFhMGE0ODgtMGVkNy00ZDIwLThmNWMtMWQ1NDViZjJmNGU4LmE3N2NmMjFmLTg2YWQtNDI2Ny1iOWM2LTY4ODJmNjY1NmJkM3gxNzkwMDE0NjQzMTI2MjU1MDAw parts=1016992026/09/21 18:17:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17002026-09-21 18:17:24.839 UTC [9663] ERROR: relation "goose_db_version" does not exist at character 3617012026-09-21 18:17:24.839 UTC [9663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17022026/09/21 18:17:24 INFO Completed upload id=117032026/09/21 18:17:24 INFO Received uploads request method=POST path=/api/pending_closures17042026/09/21 18:17:24 INFO Received uploads request method=POST path=/api/pending_closures17052026/09/21 18:17:24 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17062026/09/21 18:17:24 WARN Found objects in DB but missing from S3, will re-upload count=11707--- PASS: TestService_verifyS3Integrity (3.42s)1708=== CONT TestRedundantMultipartUpload1709--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.90s)1710=== CONT TestCacheStatsHandler17112026-09-21 18:17:24.990 UTC [9668] ERROR: relation "goose_db_version" does not exist at character 3617122026-09-21 18:17:24.990 UTC [9668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17132026/09/21 18:17:25 OK 20241026095416_initial_model.sql (135.77ms)17142026/09/21 18:17:25 OK 20251210153512_drop_unused_gin_index.sql (9.92ms)17152026/09/21 18:17:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17162026/09/21 18:17:25 OK 20251218171726_add_pins.sql (57.76ms)17172026/09/21 18:17:25 OK 20260628120000_add_object_size_and_stats.sql (38.56ms)17182026-09-21 18:17:25.132 UTC [9669] ERROR: relation "goose_db_version" does not exist at character 3617192026-09-21 18:17:25.132 UTC [9669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17202026/09/21 18:17:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmFhMGE0ODgtMGVkNy00ZDIwLThmNWMtMWQ1NDViZjJmNGU4LmZiMTAyYjI3LTYxYWYtNDZjZC04Nzc2LTgwMjYwNjdkZTZiNngxNzkwMDE0NjQzNDYyMTk1MDAw parts=1017212026/09/21 18:17:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17222026/09/21 18:17:25 INFO Completed upload id=117232026/09/21 18:17:25 OK 20241026095416_initial_model.sql (98.42ms)17242026/09/21 18:17:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017252026/09/21 18:17:25 OK 20260905000000_add_claims.sql (9.59ms)17262026/09/21 18:17:25 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)17272026/09/21 18:17:25 INFO Received uploads request method=POST path=/api/pending_closures17282026/09/21 18:17:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures17292026/09/21 18:17:25 OK 20260920000000_drop_claims.sql (3.77ms)17302026/09/21 18:17:25 goose: successfully migrated database to version: 2026092000000017312026/09/21 18:17:25 OK 20251218171726_add_pins.sql (3.52ms)17322026/09/21 18:17:25 OK 1_commit_pending_closure.sql (3.32ms)17332026/09/21 18:17:25 OK 2_object_stats_trigger.sql (1.1ms)17342026/09/21 18:17:25 goose: up to current file version: 217352026/09/21 18:17:25 INFO Aborted multipart uploads count=017362026/09/21 18:17:25 OK 20260628120000_add_object_size_and_stats.sql (18.93ms)17372026/09/21 18:17:25 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=017382026/09/21 18:17:25 INFO Vacuumed table table=pending_closures17392026/09/21 18:17:25 OK 20241026095416_initial_model.sql (39.97ms)17402026/09/21 18:17:25 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)17412026/09/21 18:17:25 OK 20260905000000_add_claims.sql (22.47ms)17422026/09/21 18:17:25 INFO Vacuumed table table=pending_objects17432026/09/21 18:17:25 OK 20251218171726_add_pins.sql (2.18ms)17442026/09/21 18:17:25 OK 20260920000000_drop_claims.sql (2.23ms)17452026/09/21 18:17:25 goose: successfully migrated database to version: 2026092000000017462026/09/21 18:17:25 INFO Vacuumed table table=multipart_uploads17472026/09/21 18:17:25 OK 1_commit_pending_closure.sql (1.39ms)17482026/09/21 18:17:25 OK 2_object_stats_trigger.sql (261.58µs)17492026/09/21 18:17:25 goose: up to current file version: 217502026/09/21 18:17:25 OK 20260628120000_add_object_size_and_stats.sql (14.93ms)17512026/09/21 18:17:25 INFO Vacuumed table table=closures17522026/09/21 18:17:25 INFO Vacuumed table table=objects17532026/09/21 18:17:25 OK 20260905000000_add_claims.sql (18.06ms)17542026/09/21 18:17:25 OK 20260920000000_drop_claims.sql (16.64ms)17552026/09/21 18:17:25 goose: successfully migrated database to version: 2026092000000017562026/09/21 18:17:25 OK 1_commit_pending_closure.sql (1.74ms)17572026/09/21 18:17:25 OK 2_object_stats_trigger.sql (301.21µs)17582026/09/21 18:17:25 goose: up to current file version: 217592026/09/21 18:17:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001760--- PASS: TestService_createPendingClosureHandler (3.63s)1761=== CONT TestReadProxyRangeRequest17622026/09/21 18:17:25 INFO Received uploads request method=POST path=/api/pending_closures1763=== NAME TestPinProtectsFromGC1764 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-9315-1570051187/TestPinProtectsFromGC2737738966/001/store/i6wfqzzbjr19hygz4m48q6iphz1k4m45-pinned-file.txt1765 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-9315-1570051187/TestPinProtectsFromGC2737738966/001/store/6m93p97acqfpcy9ar55wx1glw93kqp1b-unpinned-file.txt17662026/09/21 18:17:25 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17672026/09/21 18:17:25 INFO Received uploads request method=POST path=/api/pending_closures17682026/09/21 18:17:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17692026/09/21 18:17:25 INFO Uploading i6wfqzzbjr19hygz4m48q6iphz1k4m45-pinned-file.txt (128B)17702026/09/21 18:17:25 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17712026/09/21 18:17:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17722026/09/21 18:17:25 WARN Failed to register uploaded object key=i6wfqzzbjr19hygz4m48q6iphz1k4m45.ls error="server returned 404: 404 page not found\n"17732026/09/21 18:17:25 INFO Signed narinfos id=1 count=117742026/09/21 18:17:25 INFO Uploading 1 narinfos17752026/09/21 18:17:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17762026/09/21 18:17:25 WARN Failed to register uploaded object key=i6wfqzzbjr19hygz4m48q6iphz1k4m45.narinfo error="server returned 404: 404 page not found\n"1777--- PASS: TestService_Rustfstest (2.98s)1778=== CONT TestProxyWriteTimeout1779=== RUN TestProxyWriteTimeout/narinfo1780=== PAUSE TestProxyWriteTimeout/narinfo1781=== RUN TestProxyWriteTimeout/1_GiB_nar1782=== PAUSE TestProxyWriteTimeout/1_GiB_nar1783=== RUN TestProxyWriteTimeout/10_GiB_nar1784=== PAUSE TestProxyWriteTimeout/10_GiB_nar1785=== RUN TestProxyWriteTimeout/unknown_size1786=== PAUSE TestProxyWriteTimeout/unknown_size1787=== CONT TestReadRedirectKeepsNarinfoProxied17882026/09/21 18:17:25 INFO Completed upload id=117892026/09/21 18:17:25 INFO Upload complete. (182ms)17902026/09/21 18:17:25 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17912026/09/21 18:17:25 INFO Received uploads request method=POST path=/api/pending_closures17922026-09-21 18:17:25.680 UTC [9691] ERROR: relation "goose_db_version" does not exist at character 3617932026-09-21 18:17:25.680 UTC [9691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17942026/09/21 18:17:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17952026/09/21 18:17:25 INFO Uploading 6m93p97acqfpcy9ar55wx1glw93kqp1b-unpinned-file.txt (128B)17962026/09/21 18:17:25 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17972026/09/21 18:17:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17982026/09/21 18:17:25 INFO Signed narinfos id=2 count=117992026/09/21 18:17:25 INFO Uploading 1 narinfos18002026/09/21 18:17:25 WARN Failed to register uploaded object key=6m93p97acqfpcy9ar55wx1glw93kqp1b.ls error="server returned 404: 404 page not found\n"18012026/09/21 18:17:25 INFO Received uploads request method=POST path=/api/pending_closures18022026/09/21 18:17:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18032026/09/21 18:17:25 WARN Failed to register uploaded object key=6m93p97acqfpcy9ar55wx1glw93kqp1b.narinfo error="server returned 404: 404 page not found\n"18042026/09/21 18:17:25 INFO Completed upload id=218052026/09/21 18:17:25 INFO Upload complete. (207ms)18062026/09/21 18:17:25 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst18072026/09/21 18:17:25 INFO Received uploads request method=POST path=/api/pending_closures1808--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.03s)1809=== CONT TestCacheConfigHandler/full_config,_no_issuer1810=== CONT TestClientCADerivations18112026/09/21 18:17:25 INFO Received create pin request method=POST path=/api/pins/myapp18122026/09/21 18:17:25 OK 20241026095416_initial_model.sql (52.81ms)18132026/09/21 18:17:25 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)18142026/09/21 18:17:25 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-9315-1570051187/TestPinProtectsFromGC2737738966/001/store/i6wfqzzbjr19hygz4m48q6iphz1k4m45-pinned-file.txt narinfo_key=i6wfqzzbjr19hygz4m48q6iphz1k4m45.narinfo18152026/09/21 18:17:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures18162026/09/21 18:17:25 OK 20251218171726_add_pins.sql (7.46ms)18172026/09/21 18:17:25 INFO Garbage collection started18182026/09/21 18:17:25 INFO Aborted multipart uploads count=018192026/09/21 18:17:25 WARN Force mode enabled - objects will be deleted immediately without grace period18202026-09-21 18:17:25.818 UTC [9696] ERROR: relation "goose_db_version" does not exist at character 3618212026-09-21 18:17:25.818 UTC [9696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18222026/09/21 18:17:25 OK 20260628120000_add_object_size_and_stats.sql (10.19ms)18232026/09/21 18:17:25 OK 20260905000000_add_claims.sql (9.37ms)18242026-09-21 18:17:25.829 UTC [9698] ERROR: relation "goose_db_version" does not exist at character 3618252026-09-21 18:17:25.829 UTC [9698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18262026/09/21 18:17:25 OK 20260920000000_drop_claims.sql (874.83µs)18272026/09/21 18:17:25 goose: successfully migrated database to version: 2026092000000018282026/09/21 18:17:25 OK 1_commit_pending_closure.sql (901.04µs)18292026/09/21 18:17:25 OK 2_object_stats_trigger.sql (214.5µs)18302026/09/21 18:17:25 goose: up to current file version: 218312026-09-21 18:17:25.887 UTC [9699] ERROR: relation "goose_db_version" does not exist at character 3618322026-09-21 18:17:25.887 UTC [9699] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18332026/09/21 18:17:25 OK 20241026095416_initial_model.sql (37.65ms)18342026/09/21 18:17:25 OK 20251210153512_drop_unused_gin_index.sql (6.64ms)18352026/09/21 18:17:25 OK 20251218171726_add_pins.sql (18.42ms)18362026/09/21 18:17:25 OK 20241026095416_initial_model.sql (98.56ms)18372026/09/21 18:17:25 OK 20251210153512_drop_unused_gin_index.sql (6.97ms)18382026/09/21 18:17:26 OK 20260628120000_add_object_size_and_stats.sql (39.41ms)18392026/09/21 18:17:26 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=018402026/09/21 18:17:26 OK 20251218171726_add_pins.sql (26.34ms)18412026/09/21 18:17:26 OK 20241026095416_initial_model.sql (106.85ms)18422026/09/21 18:17:26 OK 20251210153512_drop_unused_gin_index.sql (8.36ms)18432026/09/21 18:17:26 OK 20260905000000_add_claims.sql (36.93ms)18442026/09/21 18:17:26 INFO Vacuumed table table=pending_closures18452026/09/21 18:17:26 OK 20260628120000_add_object_size_and_stats.sql (32.76ms)18462026/09/21 18:17:26 OK 20251218171726_add_pins.sql (16.05ms)18472026/09/21 18:17:26 OK 20260920000000_drop_claims.sql (33.64ms)18482026/09/21 18:17:26 goose: successfully migrated database to version: 2026092000000018492026/09/21 18:17:26 INFO Vacuumed table table=pending_objects18502026/09/21 18:17:26 OK 1_commit_pending_closure.sql (1.1ms)18512026/09/21 18:17:26 OK 2_object_stats_trigger.sql (210.83µs)18522026/09/21 18:17:26 goose: up to current file version: 218532026/09/21 18:17:26 INFO Vacuumed table table=multipart_uploads18542026/09/21 18:17:26 OK 20260628120000_add_object_size_and_stats.sql (39.46ms)18552026/09/21 18:17:26 OK 20260905000000_add_claims.sql (51.73ms)1856--- PASS: TestReadRedirectUsesPublicS3URL (1.89s)1857=== CONT TestCacheConfigHandler/no_signing_keys1858=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1859=== CONT TestCacheConfigHandler/no_cache_url_configured1860--- PASS: TestCacheConfigHandler (0.00s)1861 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1862 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1863 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1864 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1865=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle18662026/09/21 18:17:26 INFO Vacuumed table table=closures18672026/09/21 18:17:26 INFO Vacuumed table table=objects18682026/09/21 18:17:26 OK 20260920000000_drop_claims.sql (31.41ms)18692026/09/21 18:17:26 goose: successfully migrated database to version: 2026092000000018702026/09/21 18:17:26 OK 20260905000000_add_claims.sql (38.44ms)18712026/09/21 18:17:26 OK 1_commit_pending_closure.sql (1.55ms)18722026/09/21 18:17:26 OK 2_object_stats_trigger.sql (485.17µs)18732026/09/21 18:17:26 goose: up to current file version: 218742026/09/21 18:17:26 OK 20260920000000_drop_claims.sql (1.93ms)18752026/09/21 18:17:26 goose: successfully migrated database to version: 2026092000000018762026/09/21 18:17:26 OK 1_commit_pending_closure.sql (1.15ms)18772026/09/21 18:17:26 OK 2_object_stats_trigger.sql (331.42µs)18782026/09/21 18:17:26 goose: up to current file version: 218792026/09/21 18:17:26 INFO Received uploads request method=POST path=/api/pending_closures18802026/09/21 18:17:26 INFO Received uploads request method=POST path=/api/pending_closures18812026/09/21 18:17:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18822026/09/21 18:17:26 INFO Received uploads request method=POST path=/api/pending_closures1883=== NAME TestOrphanedObjectsGCStressTest1884 orphaned_objects_gc_test.go:509: Stress test completed successfully:1885 orphaned_objects_gc_test.go:510: - Active objects preserved: 201886 orphaned_objects_gc_test.go:511: - Objects deleted: 2101887 orphaned_objects_gc_test.go:512: - Total GC'd: 2101888--- PASS: TestOrphanedObjectsGCStressTest (7.95s)1889=== CONT TestResolveDBConnectionString/flag_wins1890=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1891=== CONT TestResolveDBConnectionString/nothing_configured1892=== CONT TestResolveDBConnectionString/file_when_flag_empty1893=== CONT TestResolveDBConnectionString/missing_file_is_an_error1894=== CONT TestIsValidCachePath/narinfo1895=== CONT TestIsValidCachePath/index.html1896=== CONT TestIsValidCachePath/short_hash1897=== CONT TestIsValidCachePath/wrong_extension1898=== CONT TestIsValidCachePath/leading_slash1899=== CONT TestIsValidCachePath/empty1900=== CONT TestIsValidCachePath/random_path1901=== CONT TestIsValidCachePath/invalid_char_u1902=== CONT TestIsValidCachePath/invalid_char_e1903=== CONT TestIsValidCachePath/traversal_in_middle1904=== CONT TestIsValidCachePath/traversal_parent1905=== CONT TestIsValidCachePath/nar_uncompressed1906=== CONT TestIsValidCachePath/nix-cache-info1907=== CONT TestIsValidCachePath/realisation1908=== CONT TestIsValidCachePath/log1909=== CONT TestIsValidCachePath/ls1910=== CONT TestIsValidCachePath/nar_xz1911=== CONT TestIsValidCachePath/nar_bz21912=== CONT TestIsValidCachePath/nar_zst1913=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1914=== CONT TestParseSingleRange/none1915--- PASS: TestIsValidCachePath (0.00s)1916 --- PASS: TestIsValidCachePath/narinfo (0.00s)1917 --- PASS: TestIsValidCachePath/index.html (0.00s)1918 --- PASS: TestIsValidCachePath/short_hash (0.00s)1919 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1920 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1921 --- PASS: TestIsValidCachePath/empty (0.00s)1922 --- PASS: TestIsValidCachePath/random_path (0.00s)1923 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1924 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1925 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1926 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1927 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1928 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1929 --- PASS: TestIsValidCachePath/realisation (0.00s)1930 --- PASS: TestIsValidCachePath/log (0.00s)1931 --- PASS: TestIsValidCachePath/ls (0.00s)1932 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1933 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1934 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1935 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1936=== CONT TestParseSingleRange/open-ended1937=== CONT TestParseSingleRange/start_far_past_EOF1938=== CONT TestParseSingleRange/start_past_EOF1939=== CONT TestParseSingleRange/single_byte1940=== CONT TestParseSingleRange/suffix_exceeds_size1941=== CONT TestParseSingleRange/suffix1942=== CONT TestParseSingleRange/end_clamped_to_size1943=== CONT TestParseSingleRange/malformed_both_empty1944=== CONT TestParseSingleRange/closed1945=== CONT TestParseSingleRange/malformed_end_before_start1946=== CONT TestParseSingleRange/multi-range_ignored1947=== CONT TestParseSingleRange/malformed_no_dash1948=== CONT TestParseSingleRange/unknown_unit1949--- PASS: TestParseSingleRange (0.00s)1950 --- PASS: TestParseSingleRange/none (0.00s)1951 --- PASS: TestParseSingleRange/open-ended (0.00s)1952 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1953 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1954 --- PASS: TestParseSingleRange/single_byte (0.00s)1955 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1956 --- PASS: TestParseSingleRange/suffix (0.00s)1957 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1958 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1959 --- PASS: TestParseSingleRange/closed (0.00s)1960 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1961 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1962 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1963 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1964=== CONT TestServerTLSConfig/no_client_CA1965=== CONT TestServerTLSConfig/not_a_PEM_file1966--- PASS: TestResolveDBConnectionString (0.01s)1967 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1968 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1969 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1970 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1971 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)19722026/09/21 18:17:26 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmFhMGE0ODgtMGVkNy00ZDIwLThmNWMtMWQ1NDViZjJmNGU4LjU1ZmJlYjA2LTAyMmItNDMyZi05NjNiLWZmNmU2YmVmYjI5MXgxNzkwMDE0NjQ1MzE2OTA0MDAw parts=1219732026/09/21 18:17:26 INFO Received uploads request method=POST path=/api/pending_closures1974--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.45s)1975=== CONT TestServerTLSConfig/missing_CA_file1976=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1977=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19782026/09/21 18:17:26 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]1979=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1980=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19812026/09/21 18:17:26 WARN Authentication failed token_preview=eyJhbGciOi...mzL88kRGNA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1982=== CONT TestService_RequireScope_OIDC/builder_may_write1983=== CONT TestService_RequireScope_OIDC/static_token_may_admin1984=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1985=== CONT TestService_RequireScope_OIDC/writer_implies_read1986=== CONT TestService_RequireScope_OIDC/reader_may_read1987=== CONT TestService_RequireScope_OIDC/static_token_may_write1988=== CONT TestService_RequireScope_OIDC/ops_may_not_write1989=== CONT TestService_RequireScope_OIDC/reader_may_not_write1990=== CONT TestService_RequireScope_OIDC/ops_may_admin1991=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1992=== CONT TestClientErrorHandling/InvalidStorePath1993--- PASS: TestService_AuthMiddleware_OIDC (1.14s)1994 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1995 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1996 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1997 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1998--- PASS: TestService_RequireScope_OIDC (1.26s)1999 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2000 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2001 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2002 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2003 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2004 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2005 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2006 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2007 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2008 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2009=== CONT TestClientErrorHandling/ServerNotAvailable2010--- PASS: TestServerTLSConfig (0.00s)2011 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2012 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2013 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.04s)20142026/09/21 18:17:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20152026/09/21 18:17:27 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmFhMGE0ODgtMGVkNy00ZDIwLThmNWMtMWQ1NDViZjJmNGU4LjM0MTlhZGY3LTgyZWMtNGE2Ni1iYjQwLWMxNjc5ODMzZjYyNngxNzkwMDE0NjQ2NzczMTAzMDAw20162026/09/21 18:17:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmFhMGE0ODgtMGVkNy00ZDIwLThmNWMtMWQ1NDViZjJmNGU4LjM0MTlhZGY3LTgyZWMtNGE2Ni1iYjQwLWMxNjc5ODMzZjYyNngxNzkwMDE0NjQ2NzczMTAzMDAw parts=12017--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.49s)2018=== CONT TestClientErrorHandling/InvalidAuthToken20192026-09-21 18:17:27.101 UTC [9707] ERROR: relation "goose_db_version" does not exist at character 3620202026-09-21 18:17:27.101 UTC [9707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2021--- PASS: TestCacheStatsHandler (2.25s)2022=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20232026/09/21 18:17:27 INFO Received uploads request method=POST path=/2024=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20252026/09/21 18:17:27 INFO Received complete multipart upload request method=POST path=/2026=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20272026/09/21 18:17:27 INFO Received request for more parts method=POST path=/2028=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20292026/09/21 18:17:27 INFO Received uploads request method=POST path=/2030--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2031 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2032 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2033 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2034 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2035=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20362026/09/21 18:17:27 INFO Received uploads request method=POST path=/20372026-09-21 18:17:27.172 UTC [9711] ERROR: relation "goose_db_version" does not exist at character 3620382026-09-21 18:17:27.172 UTC [9711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20392026/09/21 18:17:27 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20402026/09/21 18:17:27 OK 20241026095416_initial_model.sql (103.49ms)20412026/09/21 18:17:27 OK 20251210153512_drop_unused_gin_index.sql (7.27ms)20422026/09/21 18:17:27 OK 20251218171726_add_pins.sql (7.6ms)20432026/09/21 18:17:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.203862ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20442026/09/21 18:17:27 OK 20260628120000_add_object_size_and_stats.sql (24.04ms)20452026/09/21 18:17:27 OK 20241026095416_initial_model.sql (75.63ms)20462026/09/21 18:17:27 OK 20260905000000_add_claims.sql (36.31ms)20472026/09/21 18:17:27 OK 20251210153512_drop_unused_gin_index.sql (5.18ms)20482026/09/21 18:17:27 OK 20260920000000_drop_claims.sql (6ms)20492026/09/21 18:17:27 goose: successfully migrated database to version: 2026092000000020502026/09/21 18:17:27 OK 1_commit_pending_closure.sql (1.01ms)20512026/09/21 18:17:27 OK 2_object_stats_trigger.sql (289.13µs)20522026/09/21 18:17:27 goose: up to current file version: 220532026/09/21 18:17:27 OK 20251218171726_add_pins.sql (6.53ms)20542026/09/21 18:17:27 OK 20260628120000_add_object_size_and_stats.sql (37.11ms)2055=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20562026/09/21 18:17:27 INFO Received request for more parts method=POST path=/2057=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20582026/09/21 18:17:27 INFO Received complete multipart upload request method=POST path=/20592026/09/21 18:17:27 OK 20260905000000_add_claims.sql (55.51ms)2060--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2061 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)2062 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2063 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2064=== CONT TestIsValidUploadKey/narinfo2065=== CONT TestIsValidUploadKey/realisation_plus_in_output2066=== CONT TestIsValidUploadKey/unknown_type2067=== CONT TestIsValidUploadKey/empty_key2068=== CONT TestIsValidUploadKey/absolute2069=== CONT TestIsValidUploadKey/traversal_nar2070=== CONT TestIsValidUploadKey/traversal2071=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2072=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2073=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2074=== CONT TestIsValidUploadKey/index.html2075=== CONT TestIsValidUploadKey/nix-cache-info2076=== CONT TestIsValidUploadKey/build_log_home-manager_file2077=== CONT TestIsValidUploadKey/realisation2078=== CONT TestIsValidUploadKey/build_log_equals2079=== CONT TestIsValidUploadKey/build_log_question_mark2080=== CONT TestIsValidUploadKey/build_log_plus_in_name2081=== CONT TestIsValidUploadKey/nar_plain2082=== CONT TestIsValidUploadKey/build_log2083=== CONT TestIsValidUploadKey/listing2084=== CONT TestIsValidUploadKey/nar_xz2085=== CONT TestIsValidUploadKey/nar_zst2086--- PASS: TestIsValidUploadKey (0.00s)2087 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2088 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2089 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2090 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2091 --- PASS: TestIsValidUploadKey/absolute (0.00s)2092 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2093 --- PASS: TestIsValidUploadKey/traversal (0.00s)2094 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2095 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2096 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2097 --- PASS: TestIsValidUploadKey/index.html (0.00s)2098 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2099 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2100 --- PASS: TestIsValidUploadKey/realisation (0.00s)2101 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2102 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2103 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2104 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2105 --- PASS: TestIsValidUploadKey/build_log (0.00s)2106 --- PASS: TestIsValidUploadKey/listing (0.00s)2107 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2108 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2109=== CONT TestProxyWriteTimeout/narinfo2110=== CONT TestProxyWriteTimeout/10_GiB_nar2111=== CONT TestProxyWriteTimeout/unknown_size2112=== CONT TestProxyWriteTimeout/1_GiB_nar2113--- PASS: TestProxyWriteTimeout (0.00s)2114 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2115 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2116 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2117 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)21182026/09/21 18:17:27 OK 20260920000000_drop_claims.sql (36ms)21192026/09/21 18:17:27 goose: successfully migrated database to version: 2026092000000021202026/09/21 18:17:27 OK 1_commit_pending_closure.sql (1.05ms)21212026/09/21 18:17:27 OK 2_object_stats_trigger.sql (242.58µs)21222026/09/21 18:17:27 goose: up to current file version: 221232026/09/21 18:17:27 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.680078ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21242026-09-21 18:17:27.615 UTC [9713] ERROR: relation "goose_db_version" does not exist at character 3621252026-09-21 18:17:27.615 UTC [9713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2126--- PASS: TestReadProxyRangeRequest (2.37s)21272026/09/21 18:17:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02128=== NAME TestPinProtectsFromGC2129 client_integration_test.go:794: Pin successfully protected closure from garbage collection21302026/09/21 18:17:27 OK 20241026095416_initial_model.sql (207.15ms)21312026/09/21 18:17:27 OK 20251210153512_drop_unused_gin_index.sql (15.29ms)21322026/09/21 18:17:27 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=858.70053ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2133--- PASS: TestReadRedirectKeepsNarinfoProxied (2.40s)2134--- PASS: TestPinProtectsFromGC (5.75s)21352026/09/21 18:17:27 OK 20251218171726_add_pins.sql (41.36ms)21362026/09/21 18:17:27 OK 20260628120000_add_object_size_and_stats.sql (33.6ms)21372026/09/21 18:17:28 OK 20260905000000_add_claims.sql (41.07ms)21382026/09/21 18:17:28 OK 20260920000000_drop_claims.sql (5.47ms)21392026/09/21 18:17:28 goose: successfully migrated database to version: 2026092000000021402026/09/21 18:17:28 OK 1_commit_pending_closure.sql (3.98ms)21412026/09/21 18:17:28 OK 2_object_stats_trigger.sql (912.46µs)21422026/09/21 18:17:28 goose: up to current file version: 221432026-09-21 18:17:28.068 UTC [9714] ERROR: relation "goose_db_version" does not exist at character 3621442026-09-21 18:17:28.068 UTC [9714] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21452026/09/21 18:17:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21462026/09/21 18:17:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmFhMGE0ODgtMGVkNy00ZDIwLThmNWMtMWQ1NDViZjJmNGU4LjUxZjU1M2ZjLWI3OWUtNGYwZi1hYjU4LWVlNDA4MzM1ZWFkNXgxNzkwMDE0NjQ2Mzg4ODg5MDAw parts=122147--- PASS: TestRedundantMultipartUpload (3.34s)21482026/09/21 18:17:28 OK 20241026095416_initial_model.sql (197ms)21492026/09/21 18:17:28 OK 20251210153512_drop_unused_gin_index.sql (13.89ms)21502026/09/21 18:17:28 OK 20251218171726_add_pins.sql (25.36ms)21512026/09/21 18:17:28 OK 20260628120000_add_object_size_and_stats.sql (9.97ms)21522026/09/21 18:17:28 OK 20260905000000_add_claims.sql (30.67ms)21532026/09/21 18:17:28 OK 20260920000000_drop_claims.sql (7.75ms)21542026/09/21 18:17:28 goose: successfully migrated database to version: 2026092000000021552026/09/21 18:17:28 OK 1_commit_pending_closure.sql (1.37ms)21562026/09/21 18:17:28 OK 2_object_stats_trigger.sql (334.92µs)21572026/09/21 18:17:28 goose: up to current file version: 221582026-09-21 18:17:28.546 UTC [9717] ERROR: relation "goose_db_version" does not exist at character 3621592026-09-21 18:17:28.546 UTC [9717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21602026-09-21 18:17:28.606 UTC [9720] ERROR: relation "goose_db_version" does not exist at character 3621612026-09-21 18:17:28.606 UTC [9720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21622026/09/21 18:17:28 INFO Received uploads request method=POST path=/api/pending_closures21632026/09/21 18:17:28 OK 20241026095416_initial_model.sql (52.52ms)21642026/09/21 18:17:28 OK 20251210153512_drop_unused_gin_index.sql (5.67ms)21652026/09/21 18:17:28 OK 20251218171726_add_pins.sql (4.06ms)21662026/09/21 18:17:28 OK 20260628120000_add_object_size_and_stats.sql (8.12ms)21672026/09/21 18:17:28 OK 20260905000000_add_claims.sql (17.47ms)21682026/09/21 18:17:28 OK 20241026095416_initial_model.sql (40.06ms)21692026/09/21 18:17:28 OK 20251210153512_drop_unused_gin_index.sql (5.36ms)21702026/09/21 18:17:28 OK 20260920000000_drop_claims.sql (21.74ms)21712026/09/21 18:17:28 goose: successfully migrated database to version: 2026092000000021722026/09/21 18:17:28 OK 1_commit_pending_closure.sql (895.25µs)21732026/09/21 18:17:28 OK 2_object_stats_trigger.sql (213.71µs)21742026/09/21 18:17:28 goose: up to current file version: 221752026/09/21 18:17:28 OK 20251218171726_add_pins.sql (21.69ms)21762026/09/21 18:17:28 OK 20260628120000_add_object_size_and_stats.sql (22.36ms)21772026/09/21 18:17:28 OK 20260905000000_add_claims.sql (54.2ms)21782026/09/21 18:17:28 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.702637197s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2179=== NAME TestClientCADerivations2180 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-9315-1570051187/TestClientCADerivations3663260783/001/store/69ppcayzsajjn1pnfcgml7k6n9ab85i1-ca-test21812026/09/21 18:17:28 OK 20260920000000_drop_claims.sql (5.12ms)21822026/09/21 18:17:28 goose: successfully migrated database to version: 2026092000000021832026/09/21 18:17:28 OK 1_commit_pending_closure.sql (881.71µs)21842026/09/21 18:17:28 OK 2_object_stats_trigger.sql (215.92µs)21852026/09/21 18:17:28 goose: up to current file version: 22186 client_ca_test.go:139: Found 1 dependencies (including self)21872026/09/21 18:17:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21882026/09/21 18:17:28 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21892026/09/21 18:17:28 INFO Received uploads request method=POST path=/api/pending_closures21902026/09/21 18:17:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21912026/09/21 18:17:28 INFO Uploading 69ppcayzsajjn1pnfcgml7k6n9ab85i1-ca-test (144B)21922026/09/21 18:17:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21932026/09/21 18:17:28 WARN Failed to register uploaded object key=69ppcayzsajjn1pnfcgml7k6n9ab85i1.ls error="server returned 404: 404 page not found\n"21942026/09/21 18:17:28 WARN Failed to register uploaded object key=log/mpmkssrdlg42wg85w854a2cx61i7d9s4-ca-test.drv error="server returned 404: 404 page not found\n"21952026/09/21 18:17:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21962026/09/21 18:17:28 INFO Signed narinfos id=1 count=121972026/09/21 18:17:28 INFO Uploading 1 narinfos21982026/09/21 18:17:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21992026/09/21 18:17:28 WARN Failed to register uploaded object key=69ppcayzsajjn1pnfcgml7k6n9ab85i1.narinfo error="server returned 404: 404 page not found\n"22002026/09/21 18:17:28 INFO Completed upload id=122012026/09/21 18:17:28 INFO Upload complete. (98ms)2202 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-9315-1570051187/TestClientCADerivations3663260783/001/store/69ppcayzsajjn1pnfcgml7k6n9ab85i1-ca-test2203 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2204 Compression: zstd2205 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2206 NarSize: 1442207 References: 2208 Deriver: /nix/var/nix/builds/nix-9315-1570051187/TestClientCADerivations3663260783/001/store/mpmkssrdlg42wg85w854a2cx61i7d9s4-ca-test.drv2209 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2210 client_ca_test.go:185: Checking for realisation files in S3...2211 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2212 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2213 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket54?endpoint=http://localhost:51220®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-9315-1570051187/TestClientCADerivations3663260783/001/store'2214 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12215--- PASS: TestClientCADerivations (3.20s)22162026/09/21 18:17:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22172026/09/21 18:17:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22182026/09/21 18:17:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22192026/09/21 18:17:30 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22202026/09/21 18:17:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.065452ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22212026/09/21 18:17:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.257507ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22222026/09/21 18:17:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=793.153991ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22232026/09/21 18:17:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.737801878s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22242026/09/21 18:17:32 WARN Rate limiter enabled after throttle name=s3-test rate=522252026/09/21 18:17:32 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2226=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2227 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102228 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002229--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.63s)22302026/09/21 18:17:33 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 127.0.0.1:19999: connect: connection refused"22312026/09/21 18:17:33 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/09/21 18:17:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.995577ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22332026/09/21 18:17:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.182775ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22342026/09/21 18:17:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=734.847964ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22352026/09/21 18:17:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.611493106s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2236--- PASS: TestClientErrorHandling (0.00s)2237 --- PASS: TestClientErrorHandling/InvalidStorePath (2.05s)2238 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.03s)2239 --- PASS: TestClientErrorHandling/ServerNotAvailable (10.10s)2240PASS2241{"timestamp":"2026-09-21T18:17:36.940944Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:51338","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}22422026-09-21 18:17:37.032 UTC [9368] LOG: received smart shutdown request22432026-09-21 18:17:37.033 UTC [9368] LOG: background worker "logical replication launcher" (PID 9378) exited with exit code 122442026-09-21 18:17:37.061 UTC [9373] LOG: shutting down22452026-09-21 18:17:37.061 UTC [9373] LOG: checkpoint starting: shutdown immediate22462026-09-21 18:17:38.119 UTC [9373] LOG: checkpoint complete: wrote 13044 buffers (79.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.714 s, sync=0.318 s, total=1.058 s; sync files=19072, longest=0.001 s, average=0.001 s; distance=264768 kB, estimate=264768 kB; lsn=0/11A1D180, redo lsn=0/11A1D18022472026-09-21 18:17:38.123 UTC [9368] LOG: database system is shut down2248Running OIDC tests...2249=== RUN TestGlobMatch2250=== PAUSE TestGlobMatch2251=== RUN TestAudienceForIssuer2252=== PAUSE TestAudienceForIssuer2253=== RUN TestValidateToken_ValidToken2254=== PAUSE TestValidateToken_ValidToken2255=== RUN TestValidateToken_WrongAudience2256=== PAUSE TestValidateToken_WrongAudience2257=== RUN TestValidateToken_Expired2258=== PAUSE TestValidateToken_Expired2259=== RUN TestValidateToken_BoundClaimsMismatch2260=== PAUSE TestValidateToken_BoundClaimsMismatch2261=== RUN TestValidateToken_BoundSubjectMismatch2262=== PAUSE TestValidateToken_BoundSubjectMismatch2263=== RUN TestValidateToken_MultipleProviders2264=== PAUSE TestValidateToken_MultipleProviders2265=== RUN TestValidateToken_NoMatchingProvider2266=== PAUSE TestValidateToken_NoMatchingProvider2267=== RUN TestValidateToken_KubernetesServiceAccount2268=== PAUSE TestValidateToken_KubernetesServiceAccount2269=== RUN TestNewValidator_KubernetesRequiresCA2270=== PAUSE TestNewValidator_KubernetesRequiresCA2271=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2272=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2273=== RUN TestPins_ReservedForMatchingRule2274=== PAUSE TestPins_ReservedForMatchingRule2275=== RUN TestPins_TopLevelShorthand2276=== PAUSE TestPins_TopLevelShorthand2277=== RUN TestPins_ConfigValidation2278=== PAUSE TestPins_ConfigValidation2279=== RUN TestScopes_LegacyProviderDefaultsToWrite2280=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2281=== RUN TestScopes_Rules2282=== PAUSE TestScopes_Rules2283=== RUN TestScopes_ConfigValidation2284=== PAUSE TestScopes_ConfigValidation2285=== CONT TestGlobMatch2286=== RUN TestGlobMatch/foo_foo2287=== CONT TestValidateToken_KubernetesServiceAccount2288=== CONT TestPins_ConfigValidation2289=== CONT TestValidateToken_BoundClaimsMismatch2290=== CONT TestValidateToken_ValidToken2291=== CONT TestScopes_Rules2292=== CONT TestValidateToken_MultipleProviders2293=== CONT TestValidateToken_WrongAudience2294=== PAUSE TestGlobMatch/foo_foo2295=== RUN TestGlobMatch/foo_bar2296=== PAUSE TestGlobMatch/foo_bar2297=== RUN TestGlobMatch/*_2298=== CONT TestValidateToken_Expired2299=== CONT TestAudienceForIssuer2300=== PAUSE TestGlobMatch/*_2301=== RUN TestGlobMatch/*_anything2302=== PAUSE TestGlobMatch/*_anything2303=== RUN TestGlobMatch/foo*_foo2304=== PAUSE TestGlobMatch/foo*_foo2305=== RUN TestGlobMatch/foo*_foobar2306=== PAUSE TestGlobMatch/foo*_foobar2307=== RUN TestGlobMatch/foo*_bar2308=== PAUSE TestGlobMatch/foo*_bar2309=== RUN TestGlobMatch/*bar_bar2310=== PAUSE TestGlobMatch/*bar_bar2311=== RUN TestGlobMatch/*bar_foobar2312=== PAUSE TestGlobMatch/*bar_foobar2313=== RUN TestGlobMatch/*bar_foo2314=== PAUSE TestGlobMatch/*bar_foo2315=== RUN TestGlobMatch/foo*bar_foobar2316=== PAUSE TestGlobMatch/foo*bar_foobar2317=== RUN TestGlobMatch/foo*bar_foo123bar2318=== PAUSE TestGlobMatch/foo*bar_foo123bar2319=== RUN TestGlobMatch/foo*bar_foobarbaz2320=== PAUSE TestGlobMatch/foo*bar_foobarbaz2321=== RUN TestGlobMatch/*/*_foo/bar2322=== PAUSE TestGlobMatch/*/*_foo/bar2323=== RUN TestGlobMatch/*/*_foo2324=== PAUSE TestGlobMatch/*/*_foo2325=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2326=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2327=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02328=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02329=== RUN TestGlobMatch/refs/*/main_refs/heads/main2330=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2331=== RUN TestGlobMatch/fo?_foo2332=== PAUSE TestGlobMatch/fo?_foo2333=== RUN TestGlobMatch/fo?_fo2334=== PAUSE TestGlobMatch/fo?_fo2335=== RUN TestGlobMatch/fo?_fooo2336=== PAUSE TestGlobMatch/fo?_fooo2337=== RUN TestGlobMatch/?oo_foo2338=== PAUSE TestGlobMatch/?oo_foo2339=== RUN TestGlobMatch/?oo_boo2340=== PAUSE TestGlobMatch/?oo_boo2341=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2342=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2343=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2344=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2345=== CONT TestPins_TopLevelShorthand2346--- PASS: TestAudienceForIssuer (0.00s)2347=== CONT TestPins_ReservedForMatchingRule23482026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51429/oidc2349--- PASS: TestPins_ConfigValidation (0.00s)2350=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23512026/09/21 18:17:39 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:51424/oidc23522026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51426/oidc23532026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51425/oidc23542026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51427/oidc23552026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51430/oidc23562026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51422/oidc23572026/09/21 18:17:39 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:51431/oidc23582026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51423/oidc2359--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2360=== CONT TestNewValidator_KubernetesRequiresCA2361=== CONT TestValidateToken_NoMatchingProvider2362--- PASS: TestValidateToken_Expired (0.01s)2363--- PASS: TestPins_TopLevelShorthand (0.01s)2364=== CONT TestValidateToken_BoundSubjectMismatch23652026/09/21 18:17:39 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:51443/oidc23662026/09/21 18:17:39 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232367--- PASS: TestValidateToken_ValidToken (0.01s)2368=== CONT TestScopes_LegacyProviderDefaultsToWrite2369--- PASS: TestValidateToken_WrongAudience (0.01s)2370=== CONT TestScopes_ConfigValidation2371--- PASS: TestValidateToken_MultipleProviders (0.01s)2372=== CONT TestGlobMatch/foo_foo2373=== CONT TestGlobMatch/*/*_foo/bar2374=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2375=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2376=== CONT TestGlobMatch/?oo_boo2377=== CONT TestGlobMatch/?oo_foo2378=== CONT TestGlobMatch/fo?_fooo2379=== CONT TestGlobMatch/fo?_fo2380=== CONT TestGlobMatch/fo?_foo2381=== CONT TestGlobMatch/refs/*/main_refs/heads/main2382=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02383=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2384=== CONT TestGlobMatch/*/*_foo2385=== CONT TestGlobMatch/*bar_bar2386=== CONT TestGlobMatch/foo*bar_foobarbaz2387=== CONT TestGlobMatch/foo*bar_foo123bar2388=== CONT TestGlobMatch/foo*bar_foobar2389=== CONT TestGlobMatch/*bar_foo2390=== CONT TestGlobMatch/*bar_foobar2391=== CONT TestGlobMatch/foo*_foo2392=== CONT TestGlobMatch/foo*_bar2393=== CONT TestGlobMatch/foo*_foobar2394=== CONT TestGlobMatch/*_2395=== CONT TestGlobMatch/*_anything2396=== CONT TestGlobMatch/foo_bar2397--- PASS: TestGlobMatch (0.00s)2398 --- PASS: TestGlobMatch/foo_foo (0.00s)2399 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2400 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2402 --- PASS: TestGlobMatch/?oo_boo (0.00s)2403 --- PASS: TestGlobMatch/?oo_foo (0.00s)2404 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2405 --- PASS: TestGlobMatch/fo?_fo (0.00s)2406 --- PASS: TestGlobMatch/fo?_foo (0.00s)2407 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2409 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/*/*_foo (0.00s)2411 --- PASS: TestGlobMatch/*bar_bar (0.00s)2412 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2413 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2415 --- PASS: TestGlobMatch/*bar_foo (0.00s)2416 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2417 --- PASS: TestGlobMatch/foo*_foo (0.00s)2418 --- PASS: TestGlobMatch/foo*_bar (0.00s)2419 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2420 --- PASS: TestGlobMatch/*_ (0.00s)2421 --- PASS: TestGlobMatch/*_anything (0.00s)2422 --- PASS: TestGlobMatch/foo_bar (0.00s)24232026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51449/oidc24242026/09/21 18:17:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51448/oidc2425--- PASS: TestScopes_ConfigValidation (0.00s)24262026/09/21 18:17:39 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:514282427--- PASS: TestPins_ReservedForMatchingRule (0.01s)2428--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2429--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.00s)2430--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2431--- PASS: TestScopes_Rules (0.02s)2432--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2433--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)24342026/09/21 18:17:39 http: TLS handshake error from 127.0.0.1:51447: remote error: tls: bad certificate2435--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2436PASS2437Running hook tests...2438=== RUN TestSendPathsEmpty2439=== PAUSE TestSendPathsEmpty2440=== RUN TestQueueEnqueueAndFetch2441=== PAUSE TestQueueEnqueueAndFetch2442=== RUN TestQueueDeduplication2443=== PAUSE TestQueueDeduplication2444=== RUN TestQueueRemove2445=== PAUSE TestQueueRemove2446=== RUN TestQueueFetchBatchLimit2447=== PAUSE TestQueueFetchBatchLimit2448=== RUN TestQueueRetryMovesToBack2449=== PAUSE TestQueueRetryMovesToBack2450=== RUN TestQueueFetchRemoveLifecycle2451=== PAUSE TestQueueFetchRemoveLifecycle2452=== RUN TestQueueConcurrentWriters2453=== PAUSE TestQueueConcurrentWriters2454=== RUN TestQueueRemoveLargeClosure2455=== PAUSE TestQueueRemoveLargeClosure2456=== RUN TestServerClientIntegration2457=== PAUSE TestServerClientIntegration2458=== RUN TestServerQueueError2459=== PAUSE TestServerQueueError2460=== RUN TestGetListenerSocketActivation2461 server_test.go:210: === RUN TestGetListenerSocketActivation2462 --- PASS: TestGetListenerSocketActivation (0.00s)2463 PASS2464 2465--- PASS: TestGetListenerSocketActivation (0.01s)2466=== RUN TestDrainIsolatesPoisonPath2467=== PAUSE TestDrainIsolatesPoisonPath2468=== RUN TestRunNotBlockedByPoisonHead2469=== PAUSE TestRunNotBlockedByPoisonHead2470=== RUN TestDrainGivesUpWhenServerDown2471=== PAUSE TestDrainGivesUpWhenServerDown2472=== RUN TestFailedPathPrunedByLaterClosure2473=== PAUSE TestFailedPathPrunedByLaterClosure2474=== RUN TestWorkerUploadsAndRemoves2475=== PAUSE TestWorkerUploadsAndRemoves2476=== RUN TestWorkerSkipsGCdPaths2477=== PAUSE TestWorkerSkipsGCdPaths2478=== RUN TestWorkerPrunesClosureDeps2479=== PAUSE TestWorkerPrunesClosureDeps2480=== RUN TestDrainTimeout2481=== PAUSE TestDrainTimeout2482=== CONT TestSendPathsEmpty2483=== CONT TestServerQueueError2484--- PASS: TestSendPathsEmpty (0.00s)2485=== CONT TestQueueFetchBatchLimit2486=== CONT TestQueueRetryMovesToBack2487=== CONT TestQueueRemove2488=== CONT TestQueueDeduplication2489=== CONT TestQueueEnqueueAndFetch2490=== CONT TestQueueRemoveLargeClosure2491=== CONT TestServerClientIntegration2492=== CONT TestQueueConcurrentWriters2493=== CONT TestQueueFetchRemoveLifecycle24942026/09/21 18:17:39 ERROR Failed to queue paths error="permission denied" count=12495--- PASS: TestServerQueueError (0.00s)2496=== CONT TestWorkerUploadsAndRemoves2497--- PASS: TestServerClientIntegration (0.00s)2498=== CONT TestDrainTimeout24992026/09/21 18:17:39 INFO Upload queue status pending=225002026/09/21 18:17:39 INFO Uploading batch count=225012026/09/21 18:17:39 INFO Uploading batch count=22502--- PASS: TestQueueDeduplication (0.01s)2503=== CONT TestWorkerPrunesClosureDeps2504--- PASS: TestQueueFetchBatchLimit (0.01s)2505=== CONT TestWorkerSkipsGCdPaths2506--- PASS: TestQueueEnqueueAndFetch (0.01s)2507=== CONT TestDrainGivesUpWhenServerDown2508--- PASS: TestQueueRemove (0.01s)2509=== CONT TestFailedPathPrunedByLaterClosure2510--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2511=== CONT TestRunNotBlockedByPoisonHead2512--- PASS: TestQueueRetryMovesToBack (0.01s)2513=== CONT TestDrainIsolatesPoisonPath25142026/09/21 18:17:39 INFO Upload queue status pending=225152026/09/21 18:17:39 INFO Uploading batch count=125162026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=125172026/09/21 18:17:39 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-9315-1570051187/TestWorkerSkipsGCdPaths3008829398/002/nonexistent25182026/09/21 18:17:39 INFO Uploading batch count=125192026/09/21 18:17:39 INFO Upload queue status pending=225202026/09/21 18:17:39 INFO Uploading batch count=125212026/09/21 18:17:39 INFO Uploading batch count=125222026/09/21 18:17:39 INFO Uploading batch count=125232026/09/21 18:17:39 INFO Uploading batch count=225242026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=225252026/09/21 18:17:39 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9315-1570051187/TestDrainGivesUpWhenServerDown2084530794/002/a25262026/09/21 18:17:39 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9315-1570051187/TestDrainGivesUpWhenServerDown2084530794/002/b25272026/09/21 18:17:39 INFO Uploading batch count=425282026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=425292026/09/21 18:17:39 INFO Upload queue status pending=325302026/09/21 18:17:39 INFO Uploading batch count=125312026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=125322026/09/21 18:17:39 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9315-1570051187/TestDrainIsolatesPoisonPath2856607053/002/bbb25332026/09/21 18:17:39 INFO Uploading batch count=225342026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=225352026/09/21 18:17:39 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9315-1570051187/TestDrainGivesUpWhenServerDown2084530794/002/c25362026/09/21 18:17:39 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9315-1570051187/TestDrainGivesUpWhenServerDown2084530794/002/d25372026/09/21 18:17:39 INFO Uploading batch count=225382026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=225392026/09/21 18:17:39 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9315-1570051187/TestDrainGivesUpWhenServerDown2084530794/002/e25402026/09/21 18:17:39 INFO Uploading batch count=125412026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=125422026/09/21 18:17:39 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9315-1570051187/TestDrainGivesUpWhenServerDown2084530794/002/f25432026/09/21 18:17:39 INFO Uploading batch count=125442026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=125452026/09/21 18:17:39 ERROR Drain finished with paths left in queue remaining=102546--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)25472026/09/21 18:17:39 INFO Uploading batch count=125482026/09/21 18:17:39 ERROR Upload failed error="upload failed" count=125492026/09/21 18:17:39 ERROR Drain finished with paths left in queue remaining=12550--- PASS: TestDrainIsolatesPoisonPath (0.01s)2551--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2552--- PASS: TestWorkerUploadsAndRemoves (0.03s)2553--- PASS: TestWorkerPrunesClosureDeps (0.03s)2554--- PASS: TestWorkerSkipsGCdPaths (0.03s)2555--- PASS: TestQueueRemoveLargeClosure (0.06s)2556--- PASS: TestQueueConcurrentWriters (0.15s)25572026/09/21 18:17:39 ERROR Upload failed error="context deadline exceeded" count=225582026/09/21 18:17:39 ERROR Drain finished with paths left in queue remaining=42559--- PASS: TestDrainTimeout (0.21s)25602026/09/21 18:17:40 INFO Uploading batch count=125612026/09/21 18:17:40 INFO Uploading batch count=125622026/09/21 18:17:40 INFO Uploading batch count=125632026/09/21 18:17:40 ERROR Upload failed error="upload failed" count=125642026/09/21 18:17:40 INFO Uploading batch count=125652026/09/21 18:17:40 ERROR Upload failed error="upload failed" count=125662026/09/21 18:17:40 INFO Uploading batch count=125672026/09/21 18:17:40 ERROR Upload failed error="upload failed" count=125682026/09/21 18:17:40 INFO Uploading batch count=125692026/09/21 18:17:40 ERROR Upload failed error="upload failed" count=125702026/09/21 18:17:40 ERROR Drain finished with paths left in queue remaining=12571--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2572PASS