niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #187
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestStreamPushReportsEveryPath48=== PAUSE TestStreamPushReportsEveryPath49=== RUN TestStreamPushBatchesUnderLoad50=== PAUSE TestStreamPushBatchesUnderLoad51=== RUN TestStreamPushIsolatesFailures52=== PAUSE TestStreamPushIsolatesFailures53=== RUN TestStreamPushGivesUpOnDeadServer54=== PAUSE TestStreamPushGivesUpOnDeadServer55=== RUN TestSetClientTLS56=== PAUSE TestSetClientTLS57=== RUN TestSetClientTLSDoesNotMutateDefaultTransport58=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport59=== RUN TestSetClientTLSErrors60=== PAUSE TestSetClientTLSErrors61=== RUN TestStaticToken62=== PAUSE TestStaticToken63=== RUN TestFileTokenReadsAndCaches64=== PAUSE TestFileTokenReadsAndCaches65=== RUN TestFileTokenMissing66=== PAUSE TestFileTokenMissing67=== RUN TestFileTokenEmpty68=== PAUSE TestFileTokenEmpty69=== RUN TestScriptTokenNoExpiryRerunsEveryCall70=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall71=== RUN TestScriptTokenCachesUntilRefresh72=== PAUSE TestScriptTokenCachesUntilRefresh73=== RUN TestScriptTokenEmptyToken74=== PAUSE TestScriptTokenEmptyToken75=== RUN TestScriptTokenBadJSON76=== PAUSE TestScriptTokenBadJSON77=== RUN TestScriptTokenScriptFails78=== PAUSE TestScriptTokenScriptFails79=== RUN TestScriptTokenEmptyCommand80=== PAUSE TestScriptTokenEmptyCommand81=== CONT TestDoServerRequestAttachesToken82=== CONT TestScriptTokenEmptyCommand83=== CONT TestConvertHashToNix3284--- PASS: TestScriptTokenEmptyCommand (0.00s)85=== CONT TestScriptTokenScriptFails86=== RUN TestConvertHashToNix32/SRI_format_to_Nix3287=== CONT TestDumpPathMatchesNix88=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3289=== RUN TestConvertHashToNix32/already_Nix32_format90=== PAUSE TestConvertHashToNix32/already_Nix32_format91=== CONT TestShellSplit92=== CONT TestParsePathInfoJSONMultiplePaths93=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths94=== CONT TestParsePathInfoJSON95=== RUN TestParsePathInfoJSON/Nix_format96=== CONT TestPathInfoHashCompatibility97=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)98=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)99=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon100=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon101=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI102=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI103=== CONT TestGetStorePathHash104=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512105=== CONT TestStaticToken106=== CONT TestScriptTokenBadJSON107=== CONT TestDumpPathWriterError108=== CONT TestScriptTokenEmptyToken109=== CONT TestScriptTokenCachesUntilRefresh110=== CONT TestScriptTokenNoExpiryRerunsEveryCall111=== CONT TestFileTokenEmpty112=== CONT TestFileTokenMissing113=== CONT TestFileTokenReadsAndCaches114=== CONT TestEncodeNixBase32115=== CONT TestEncodeNixBase32WithRealHash116=== CONT TestStreamPushGivesUpOnDeadServer117=== CONT TestSetClientTLSErrors118=== CONT TestSetClientTLSDoesNotMutateDefaultTransport119=== CONT TestSetClientTLS120=== CONT TestStreamPushBatchesUnderLoad121=== RUN TestConvertHashToNix32/invalid_format122--- PASS: TestShellSplit (0.00s)123=== CONT TestStreamPushIsolatesFailures124=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths126=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths127--- PASS: TestStaticToken (0.00s)128=== RUN TestEncodeNixBase32/test_string_hash129=== PAUSE TestEncodeNixBase32/test_string_hash130=== RUN TestEncodeNixBase32/empty_input131=== PAUSE TestEncodeNixBase32/empty_input132=== CONT TestDumpPathSingleFile1332026/09/09 10:29:17 ERROR Upload failed error="connection refused" count=201342026/09/09 10:29:17 ERROR Server seems unavailable, giving up on batch untried=17135--- PASS: TestEncodeNixBase32WithRealHash (0.00s)136--- PASS: TestScriptTokenScriptFails (0.00s)137=== RUN TestGetStorePathHash/valid_store_path138=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121392026/09/09 10:29:17 ERROR Upload failed error="bad path" count=3140=== CONT TestUploadMultipart_SupersededByPeer141=== RUN TestUploadMultipart_SupersededByPeer/exists142=== CONT TestResolveStorePath143=== CONT TestShellSplitErrors144=== CONT TestPartSizeForNAR145=== PAUSE TestParsePathInfoJSON/Nix_format146=== RUN TestParsePathInfoJSON/Lix_format147--- PASS: TestFileTokenMissing (0.00s)148--- PASS: TestScriptTokenBadJSON (0.00s)149=== CONT TestDoWithRetry_BodyReplayedViaGetBody150=== PAUSE TestGetStorePathHash/valid_store_path151=== PAUSE TestConvertHashToNix32/invalid_format152=== CONT TestCaseHackSuffix153=== CONT TestFilterOversizedClosures154=== RUN TestGetStorePathHash/basename_without_hyphen_should_error155=== RUN TestFilterOversizedClosures/no_limit_keeps_everything156=== CONT TestStreamPushReportsEveryPath157=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess158=== CONT TestRateLimiterFeedback159=== CONT TestPathInfoCACompatibility160=== RUN TestPathInfoCACompatibility/null_ca_field161=== RUN TestRateLimiterFeedback/429_enables_limiter162=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1632026/09/09 10:29:17 WARN Rate limiter enabled after throttle name=server-test rate=5164=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything165=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped166=== PAUSE TestPathInfoCACompatibility/null_ca_field167=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== RUN TestPartSizeForNAR/zero_stays_at_minimum169=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum170=== RUN TestPartSizeForNAR/small_stays_at_minimum171=== PAUSE TestPartSizeForNAR/small_stays_at_minimum172=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI173=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped174=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512175=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon176=== CONT TestConvertHashToNix32/SRI_format_to_Nix32177=== CONT TestConvertHashToNix32/already_Nix32_format178=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum179--- PASS: TestScriptTokenEmptyToken (0.00s)180=== CONT TestEncodeNixBase32/empty_input181=== PAUSE TestUploadMultipart_SupersededByPeer/exists1822026/09/09 10:29:17 WARN Rate limiter enabled after throttle name=server-test rate=51832026/09/09 10:29:17 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45857184=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error185=== CONT TestEncodeNixBase32/test_string_hash186=== PAUSE TestRateLimiterFeedback/429_enables_limiter187=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error188=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths189=== RUN TestPathInfoCACompatibility/old_string_format_-_text190=== PAUSE TestParsePathInfoJSON/Lix_format191=== RUN TestFilterOversizedClosures/all_closures_skipped192=== CONT TestConvertHashToNix32/invalid_format193=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum194--- PASS: TestStreamPushIsolatesFailures (0.00s)195=== PAUSE TestFilterOversizedClosures/all_closures_skipped1962026/09/09 10:29:17 WARN Rate limiter backed off name=server-test rate=5197=== CONT TestFilterOversizedClosures/no_limit_keeps_everything198=== CONT TestFilterOversizedClosures/all_closures_skipped1992026/09/09 10:29:17 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45857200=== RUN TestRateLimiterFeedback/503_enables_limiter201=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error202=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error203=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error2042026/09/09 10:29:17 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50205=== CONT TestGetStorePathHash/valid_store_path206=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error207=== RUN TestParsePathInfoJSON/empty_input208=== RUN TestSetClientTLSErrors/missing_cert_file209=== PAUSE TestSetClientTLSErrors/missing_cert_file210=== PAUSE TestParsePathInfoJSON/empty_input211--- PASS: TestFileTokenEmpty (0.01s)212=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts213=== RUN TestUploadMultipart_SupersededByPeer/missing214=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2152026/09/09 10:29:17 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=2000216=== PAUSE TestRateLimiterFeedback/503_enables_limiter217=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter218=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter219=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text220=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error221=== CONT TestGetStorePathHash/basename_without_hyphen_should_error222=== RUN TestSetClientTLSErrors/missing_key_file223=== PAUSE TestSetClientTLSErrors/missing_key_file224=== RUN TestSetClientTLSErrors/missing_ca_file225=== RUN TestParsePathInfoJSON/whitespace_only226--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)227--- PASS: TestShellSplitErrors (0.00s)228=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts229=== PAUSE TestUploadMultipart_SupersededByPeer/missing230=== CONT TestUploadMultipart_SupersededByPeer/exists231=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter232=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive233=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive234=== RUN TestPathInfoCACompatibility/new_structured_format_-_text235=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text236=== RUN TestSetClientTLS/rejects_connection_without_client_cert237=== PAUSE TestSetClientTLSErrors/missing_ca_file238=== PAUSE TestParsePathInfoJSON/whitespace_only239--- PASS: TestDoServerRequestAttachesToken (0.01s)240=== RUN TestPartSizeForNAR/1_TiB241=== CONT TestUploadMultipart_SupersededByPeer/missing242=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter243=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method244=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method245=== CONT TestPathInfoCACompatibility/null_ca_field246=== CONT TestPathInfoCACompatibility/new_structured_format_-_text247=== CONT TestPathInfoCACompatibility/old_string_format_-_text248=== RUN TestSetClientTLSErrors/invalid_ca_file249=== PAUSE TestSetClientTLSErrors/invalid_ca_file250=== CONT TestSetClientTLSErrors/invalid_ca_file251=== CONT TestSetClientTLSErrors/missing_ca_file252=== CONT TestSetClientTLSErrors/missing_key_file253=== RUN TestParsePathInfoJSON/invalid_JSON254=== PAUSE TestPartSizeForNAR/1_TiB255=== CONT TestRateLimiterFeedback/429_enables_limiter256=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter257=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter258=== CONT TestRateLimiterFeedback/503_enables_limiter259=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive260=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert261=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method262=== CONT TestSetClientTLSErrors/missing_cert_file263--- PASS: TestFileTokenReadsAndCaches (0.01s)264--- PASS: TestResolveStorePath (0.01s)2652026/09/09 10:29:17 WARN Rate limiter enabled after throttle name=server-test rate=52662026/09/09 10:29:17 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:41117267--- PASS: TestStreamPushReportsEveryPath (0.01s)268=== PAUSE TestParsePathInfoJSON/invalid_JSON269=== CONT TestParsePathInfoJSON/Nix_format270=== CONT TestParsePathInfoJSON/whitespace_only271=== CONT TestParsePathInfoJSON/empty_input272=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2732026/09/09 10:29:17 WARN Rate limiter backed off name=server-test rate=5274=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA275=== CONT TestParsePathInfoJSON/Lix_format276=== RUN TestPartSizeForNAR/5_TiB_S3_max_object2772026/09/09 10:29:17 WARN Rate limiter enabled after throttle name=server-test rate=5278=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object2792026/09/09 10:29:17 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36273280=== RUN TestPartSizeForNAR/capped_at_5_GiB281=== PAUSE TestPartSizeForNAR/capped_at_5_GiB282=== CONT TestPartSizeForNAR/zero_stays_at_minimum283=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum284=== CONT TestParsePathInfoJSON/invalid_JSON285=== CONT TestPartSizeForNAR/small_stays_at_minimum286--- PASS: TestPathInfoHashCompatibility (0.00s)287 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)288 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)289 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)290 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)291--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)292=== RUN TestSetClientTLS/preserves_debug_logging_transport293=== CONT TestPartSizeForNAR/1_TiB294=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2952026/09/09 10:29:17 WARN Rate limiter backed off name=server-test rate=5296=== CONT TestSetClientTLS/rejects_connection_without_client_cert297=== CONT TestPartSizeForNAR/capped_at_5_GiB298=== CONT TestSetClientTLS/preserves_debug_logging_transport299=== CONT TestPartSizeForNAR/5_TiB_S3_max_object300=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts301--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)302=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA303--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)304--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)305--- PASS: TestPathInfoCACompatibility (0.01s)306 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)307 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)308 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)309 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)310 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)311--- PASS: TestParsePathInfoJSON (0.03s)312 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)313 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)314 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)315 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)316 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)317--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)318 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)319 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)320--- PASS: TestRateLimiterFeedback (0.01s)321 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)322 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)325--- PASS: TestPartSizeForNAR (0.02s)326 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)327 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)328 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)329 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)330 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)331 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)332 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)333--- PASS: TestConvertHashToNix32 (0.01s)334 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)335 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)336 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)337--- PASS: TestEncodeNixBase32 (0.00s)338 --- PASS: TestEncodeNixBase32/empty_input (0.00s)339 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)340--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)341 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)342 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)343--- PASS: TestFilterOversizedClosures (0.01s)344 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)345 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)346 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)347--- PASS: TestGetStorePathHash (0.02s)348 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)349 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)350 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)351 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)352--- PASS: TestSetClientTLSErrors (0.03s)353 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)354 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)355 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)356 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)3572026/09/09 10:29:17 http: TLS handshake error from 127.0.0.1:58464: remote error: tls: bad certificate358--- PASS: TestSetClientTLS (0.03s)359 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)360 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)361 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)362--- PASS: TestDumpPathWriterError (0.06s)363--- PASS: TestCaseHackSuffix (0.05s)364--- PASS: TestDumpPathSingleFile (0.06s)365--- PASS: TestDumpPathMatchesNix (0.10s)366--- PASS: TestStreamPushBatchesUnderLoad (0.11s)367--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)368PASS369Running server tests...370The files belonging to this database system will be owned by user "nixbld".371This user must also own the server process.372373The database cluster will be initialized with locale "C".374The default database encoding has accordingly been set to "SQL_ASCII".375The default text search configuration will be set to "english".376377Data page checksums are enabled.378379creating directory /build/postgres2314945916/data ... ok380creating subdirectories ... ok381selecting dynamic shared memory implementation ... posix382selecting default "max_connections" ... 100383selecting default "shared_buffers" ... 128MB384selecting default time zone ... UTC385creating configuration files ... ok386running bootstrap script ... ok387performing post-bootstrap initialization ... ok388syncing data to disk ... ok389390initdb: warning: enabling "trust" authentication for local connections391initdb: 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.392393Success. You can now start the database server using:394395 pg_ctl -D /build/postgres2314945916/data -l logfile start396397/build/postgres2314945916:5432 - no response3982026-09-09 10:29:19.646 UTC [111] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3992026-09-09 10:29:19.648 UTC [111] LOG: listening on Unix socket "/build/postgres2314945916/.s.PGSQL.5432"4002026-09-09 10:29:19.653 UTC [118] LOG: database system was shut down at 2026-09-09 10:29:19 UTC4012026-09-09 10:29:19.657 UTC [111] LOG: database system is ready to accept connections402/build/postgres2314945916:5432 - accepting connections403=== RUN TestService_AuthMiddleware404=== PAUSE TestService_AuthMiddleware405=== RUN TestService_AuthMiddleware_MTLSProxyHeader406=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader407=== RUN TestService_AuthMiddleware_MTLSBoundSubjects408=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects409=== RUN TestService_ReadAuthMiddleware410=== PAUSE TestService_ReadAuthMiddleware411=== RUN TestService_AuthMiddleware_OIDC412=== PAUSE TestService_AuthMiddleware_OIDC413=== RUN TestService_RequireScope_OIDC414=== PAUSE TestService_RequireScope_OIDC415=== RUN TestService_ReadScope_PublicByDefault416=== PAUSE TestService_ReadScope_PublicByDefault417=== RUN TestCacheConfigHandler418=== PAUSE TestCacheConfigHandler419=== RUN TestCacheStatsHandler420=== PAUSE TestCacheStatsHandler421=== RUN TestClientCADerivations422=== PAUSE TestClientCADerivations423=== RUN TestClientErrorHandling424=== PAUSE TestClientErrorHandling425=== RUN TestClientIntegration426=== PAUSE TestClientIntegration427=== RUN TestClientMultipleUploads428=== PAUSE TestClientMultipleUploads429=== RUN TestClientWithDependencies430=== PAUSE TestClientWithDependencies431=== RUN TestPinProtectsFromGC432=== PAUSE TestPinProtectsFromGC433=== RUN TestResolveDBConnectionString434=== PAUSE TestResolveDBConnectionString435=== RUN TestGCAdvisoryLockBlocksConcurrentRun4362026-09-09 10:29:20.087 UTC [525] ERROR: relation "goose_db_version" does not exist at character 364372026-09-09 10:29:20.087 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4382026/09/09 10:29:20 OK 20241026095416_initial_model.sql (15.32ms)4392026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)4402026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.28ms)4412026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)4422026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200004432026/09/09 10:29:20 OK 1_commit_pending_closure.sql (2.46ms)4442026/09/09 10:29:20 OK 2_object_stats_trigger.sql (1.22ms)4452026/09/09 10:29:20 goose: up to current file version: 2446--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.23s)447=== RUN TestGCBugBareHashReferences448=== PAUSE TestGCBugBareHashReferences449=== RUN TestGCMetrics450=== PAUSE TestGCMetrics451=== RUN TestGCTaskStore_StartNew452=== PAUSE TestGCTaskStore_StartNew453=== RUN TestGCTaskStore_DeduplicateSameParams454=== PAUSE TestGCTaskStore_DeduplicateSameParams455=== RUN TestGCTaskStore_ConflictDifferentParams456=== PAUSE TestGCTaskStore_ConflictDifferentParams457=== RUN TestGCTaskStore_GetEmpty458=== PAUSE TestGCTaskStore_GetEmpty459=== RUN TestGCTaskStore_GetReturnsLatest460=== PAUSE TestGCTaskStore_GetReturnsLatest461=== RUN TestGCTaskStore_CompletedAllowsNewTask462=== PAUSE TestGCTaskStore_CompletedAllowsNewTask463=== RUN TestGCTaskStore_PhaseUpdates464=== PAUSE TestGCTaskStore_PhaseUpdates465=== RUN TestGCTaskStore_Fail466=== PAUSE TestGCTaskStore_Fail467=== RUN TestGracefulShutdownDrainsInflight468=== PAUSE TestGracefulShutdownDrainsInflight469=== RUN TestService_healthCheckHandler470=== PAUSE TestService_healthCheckHandler471=== RUN TestService_readinessHandler472=== PAUSE TestService_readinessHandler473=== RUN TestGenerateLandingPage474=== PAUSE TestGenerateLandingPage475=== RUN TestCacheConfigHandlerMaxNarSize476=== PAUSE TestCacheConfigHandlerMaxNarSize477=== RUN TestCreatePendingClosureRejectsOversizedNAR478=== PAUSE TestCreatePendingClosureRejectsOversizedNAR479=== RUN TestNARDeduplicationMetadataUploadBug480=== PAUSE TestNARDeduplicationMetadataUploadBug481=== RUN TestMetricsInventory482=== PAUSE TestMetricsInventory483=== RUN TestService_NativeMTLS484=== PAUSE TestService_NativeMTLS485=== RUN TestServerTLSConfig486=== PAUSE TestServerTLSConfig487=== RUN TestMultipartCleanup488=== PAUSE TestMultipartCleanup489=== RUN TestObjectStatsTrigger490=== PAUSE TestObjectStatsTrigger491=== RUN TestOrphanedObjectsGC492=== PAUSE TestOrphanedObjectsGC493=== RUN TestOrphanedObjectsGCStressTest494=== PAUSE TestOrphanedObjectsGCStressTest495=== RUN TestResurrectedObjectNotDeleted496=== PAUSE TestResurrectedObjectNotDeleted497=== RUN TestParseSingleRange498=== PAUSE TestParseSingleRange499=== RUN TestIsValidCachePath500=== PAUSE TestIsValidCachePath501=== RUN TestReadProxyNarinfo502=== PAUSE TestReadProxyNarinfo503=== RUN TestReadProxyNarinfoAlreadyDecompressed504=== PAUSE TestReadProxyNarinfoAlreadyDecompressed505=== RUN TestReadProxyNarStreaming506=== PAUSE TestReadProxyNarStreaming507=== RUN TestReadProxy404508=== PAUSE TestReadProxy404509=== RUN TestReadProxyInvalidPath510=== PAUSE TestReadProxyInvalidPath511=== RUN TestReadProxyHead512=== PAUSE TestReadProxyHead513=== RUN TestReadProxyConditionalGet514=== PAUSE TestReadProxyConditionalGet515=== RUN TestReadProxyRootRedirectsToIndexHTML516=== PAUSE TestReadProxyRootRedirectsToIndexHTML517=== RUN TestReadProxyDisabled518=== PAUSE TestReadProxyDisabled519=== RUN TestReadRedirectNar520=== PAUSE TestReadRedirectNar521=== RUN TestReadRedirectKeepsNarinfoProxied522=== PAUSE TestReadRedirectKeepsNarinfoProxied523=== RUN TestReadProxyRangeRequest524=== PAUSE TestReadProxyRangeRequest525=== RUN TestReadRedirectUsesPublicS3URL526=== PAUSE TestReadRedirectUsesPublicS3URL527=== RUN TestRedundantMultipartUpload528=== PAUSE TestRedundantMultipartUpload529=== RUN TestCompleteMultipartUpload_ErrorButObjectExists530=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists531=== RUN TestCompletedNarNotReofferedAcrossClosures532=== PAUSE TestCompletedNarNotReofferedAcrossClosures533=== RUN TestPresignedUploadRegisteredBeforeCommit534=== PAUSE TestPresignedUploadRegisteredBeforeCommit535=== RUN TestService_Rustfstest536=== PAUSE TestService_Rustfstest537=== RUN TestParseSize538=== PAUSE TestParseSize539=== RUN TestSkippedUploadsHandler540=== PAUSE TestSkippedUploadsHandler541=== RUN TestSystemdListenerNotActivated542--- PASS: TestSystemdListenerNotActivated (0.00s)543=== RUN TestWatchdogBeatsWhenHealthy544--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)545=== RUN TestWatchdogSkipsWhenUnhealthy5462026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5472026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5482026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5492026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5502026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5512026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5522026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5532026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5542026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5552026/09/09 10:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"556--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)557=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle558=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle559=== RUN TestProxyWriteTimeout560=== PAUSE TestProxyWriteTimeout561=== RUN TestIsValidUploadKey562=== PAUSE TestIsValidUploadKey563=== RUN TestUploadHandlersRejectInvalidKeys564=== PAUSE TestUploadHandlersRejectInvalidKeys565=== RUN TestUploadHandlersRejectOversizedBody566=== PAUSE TestUploadHandlersRejectOversizedBody567=== RUN TestService_cleanupPendingClosuresHandler568=== PAUSE TestService_cleanupPendingClosuresHandler569=== RUN TestService_createPendingClosureHandler570=== PAUSE TestService_createPendingClosureHandler571=== RUN TestService_verifyS3Integrity572=== PAUSE TestService_verifyS3Integrity573=== RUN TestCompleteMultipartUnregistered574=== PAUSE TestCompleteMultipartUnregistered575=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT576=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT577=== CONT TestService_verifyS3Integrity578=== CONT TestGCTaskStore_GetReturnsLatest579--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)580=== CONT TestReadRedirectKeepsNarinfoProxied581=== CONT TestService_AuthMiddleware582=== CONT TestService_createPendingClosureHandler583=== CONT TestService_cleanupPendingClosuresHandler584=== CONT TestUploadHandlersRejectOversizedBody585=== CONT TestUploadHandlersRejectInvalidKeys586=== CONT TestIsValidUploadKey587=== CONT TestProxyWriteTimeout588=== RUN TestProxyWriteTimeout/narinfo589=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle590=== CONT TestSkippedUploadsHandler591=== CONT TestParseSize592=== CONT TestService_Rustfstest593=== CONT TestPresignedUploadRegisteredBeforeCommit594=== CONT TestCompletedNarNotReofferedAcrossClosures595=== CONT TestCompleteMultipartUpload_ErrorButObjectExists596=== CONT TestRedundantMultipartUpload597=== CONT TestReadRedirectUsesPublicS3URL598=== CONT TestReadProxyRangeRequest599=== CONT TestGracefulShutdownDrainsInflight600=== CONT TestGCTaskStore_Fail601=== CONT TestGCTaskStore_PhaseUpdates602=== CONT TestGCTaskStore_CompletedAllowsNewTask603=== CONT TestService_healthCheckHandler604=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info605=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info606=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal607=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal608=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key609=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key610=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key611=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key612=== PAUSE TestProxyWriteTimeout/narinfo613=== RUN TestProxyWriteTimeout/1_GiB_nar614=== PAUSE TestProxyWriteTimeout/1_GiB_nar615=== RUN TestProxyWriteTimeout/10_GiB_nar616=== PAUSE TestProxyWriteTimeout/10_GiB_nar617=== RUN TestProxyWriteTimeout/unknown_size618=== PAUSE TestProxyWriteTimeout/unknown_size619--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)620=== RUN TestIsValidUploadKey/narinfo621=== CONT TestReadProxyConditionalGet622=== PAUSE TestIsValidUploadKey/narinfo623--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)624=== RUN TestIsValidUploadKey/nar_zst625=== PAUSE TestIsValidUploadKey/nar_zst626=== RUN TestIsValidUploadKey/nar_xz627=== PAUSE TestIsValidUploadKey/nar_xz628=== RUN TestIsValidUploadKey/nar_plain629=== CONT TestReadRedirectNar630=== CONT TestReadProxyRootRedirectsToIndexHTML631=== CONT TestReadProxyDisabled632--- PASS: TestGCTaskStore_Fail (0.00s)633=== CONT TestReadProxyHead634=== PAUSE TestIsValidUploadKey/nar_plain635=== RUN TestIsValidUploadKey/listing636=== PAUSE TestIsValidUploadKey/listing637=== RUN TestIsValidUploadKey/build_log638=== PAUSE TestIsValidUploadKey/build_log639=== RUN TestIsValidUploadKey/build_log_home-manager_file640=== PAUSE TestIsValidUploadKey/build_log_home-manager_file641=== RUN TestIsValidUploadKey/build_log_plus_in_name642=== PAUSE TestIsValidUploadKey/build_log_plus_in_name643=== RUN TestIsValidUploadKey/build_log_question_mark644=== PAUSE TestIsValidUploadKey/build_log_question_mark645=== RUN TestIsValidUploadKey/build_log_equals646=== PAUSE TestIsValidUploadKey/build_log_equals647=== RUN TestIsValidUploadKey/realisation648=== PAUSE TestIsValidUploadKey/realisation649=== RUN TestIsValidUploadKey/realisation_plus_in_output650=== PAUSE TestIsValidUploadKey/realisation_plus_in_output651=== RUN TestIsValidUploadKey/nix-cache-info652=== PAUSE TestIsValidUploadKey/nix-cache-info653=== RUN TestIsValidUploadKey/index.html654=== PAUSE TestIsValidUploadKey/index.html655=== RUN TestIsValidUploadKey/narinfo_key,_nar_type656=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type657=== RUN TestIsValidUploadKey/nar_key,_narinfo_type658=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type659=== RUN TestIsValidUploadKey/listing_key,_narinfo_type660=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type661=== RUN TestIsValidUploadKey/traversal662=== PAUSE TestIsValidUploadKey/traversal663=== RUN TestIsValidUploadKey/traversal_nar664=== PAUSE TestIsValidUploadKey/traversal_nar665=== RUN TestIsValidUploadKey/absolute666=== PAUSE TestIsValidUploadKey/absolute667=== RUN TestIsValidUploadKey/empty_key668=== PAUSE TestIsValidUploadKey/empty_key669=== RUN TestIsValidUploadKey/unknown_type670=== PAUSE TestIsValidUploadKey/unknown_type671=== CONT TestReadProxyInvalidPath6722026/09/09 10:29:20 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000673--- PASS: TestParseSize (0.00s)674=== CONT TestReadProxy4046752026/09/09 10:29:20 INFO Starting HTTP server address=127.0.0.1:37787676--- PASS: TestSkippedUploadsHandler (0.09s)677=== CONT TestReadProxyNarStreaming6782026/09/09 10:29:20 INFO Shutdown signal received, draining in-flight requests timeout=10s679--- PASS: TestGracefulShutdownDrainsInflight (0.07s)680=== CONT TestReadProxyNarinfoAlreadyDecompressed6812026-09-09 10:29:20.607 UTC [601] ERROR: relation "goose_db_version" does not exist at character 366822026-09-09 10:29:20.607 UTC [601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6832026-09-09 10:29:20.607 UTC [595] ERROR: relation "goose_db_version" does not exist at character 366842026-09-09 10:29:20.607 UTC [595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026-09-09 10:29:20.607 UTC [597] ERROR: relation "goose_db_version" does not exist at character 366862026-09-09 10:29:20.607 UTC [597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6872026-09-09 10:29:20.607 UTC [599] ERROR: relation "goose_db_version" does not exist at character 366882026-09-09 10:29:20.607 UTC [599] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6892026-09-09 10:29:20.607 UTC [596] ERROR: relation "goose_db_version" does not exist at character 366902026-09-09 10:29:20.607 UTC [596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6912026-09-09 10:29:20.615 UTC [602] ERROR: relation "goose_db_version" does not exist at character 366922026-09-09 10:29:20.615 UTC [602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6932026-09-09 10:29:20.621 UTC [603] ERROR: relation "goose_db_version" does not exist at character 366942026-09-09 10:29:20.621 UTC [603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC695=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure696=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure697=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart698=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart699=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts700=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts701=== CONT TestReadProxyNarinfo7022026-09-09 10:29:20.638 UTC [604] ERROR: relation "goose_db_version" does not exist at character 367032026-09-09 10:29:20.638 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7042026-09-09 10:29:20.663 UTC [610] ERROR: relation "goose_db_version" does not exist at character 367052026-09-09 10:29:20.663 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7062026-09-09 10:29:20.664 UTC [611] ERROR: relation "goose_db_version" does not exist at character 367072026-09-09 10:29:20.664 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7082026/09/09 10:29:20 OK 20241026095416_initial_model.sql (28.8ms)7092026/09/09 10:29:20 OK 20241026095416_initial_model.sql (32.74ms)7102026/09/09 10:29:20 OK 20241026095416_initial_model.sql (30.58ms)7112026/09/09 10:29:20 OK 20241026095416_initial_model.sql (28.48ms)7122026/09/09 10:29:20 OK 20241026095416_initial_model.sql (29.72ms)7132026/09/09 10:29:20 OK 20241026095416_initial_model.sql (32.98ms)7142026/09/09 10:29:20 OK 20241026095416_initial_model.sql (32.33ms)7152026/09/09 10:29:20 OK 20241026095416_initial_model.sql (18.52ms)7162026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)7172026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)7182026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (4.37ms)7192026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (4.61ms)7202026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (4.7ms)7212026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)7222026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (4.58ms)7232026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (4.79ms)7242026/09/09 10:29:20 OK 20251218171726_add_pins.sql (7.49ms)7252026-09-09 10:29:20.678 UTC [612] ERROR: relation "goose_db_version" does not exist at character 367262026-09-09 10:29:20.678 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7272026/09/09 10:29:20 OK 20251218171726_add_pins.sql (7.68ms)7282026/09/09 10:29:20 OK 20251218171726_add_pins.sql (8.25ms)7292026/09/09 10:29:20 OK 20251218171726_add_pins.sql (8.68ms)7302026/09/09 10:29:20 OK 20251218171726_add_pins.sql (8.31ms)7312026/09/09 10:29:20 OK 20251218171726_add_pins.sql (8.67ms)7322026/09/09 10:29:20 OK 20251218171726_add_pins.sql (8.55ms)7332026/09/09 10:29:20 OK 20251218171726_add_pins.sql (9.8ms)7342026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (7.56ms)7352026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007362026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (17.02ms)7372026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007382026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (17.16ms)7392026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (17.5ms)7402026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (15.96ms)7412026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007422026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (17.59ms)7432026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007442026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007452026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007462026/09/09 10:29:20 OK 20241026095416_initial_model.sql (24.43ms)7472026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (17.27ms)7482026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007492026/09/09 10:29:20 OK 1_commit_pending_closure.sql (14.19ms)7502026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (17.43ms)7512026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007522026/09/09 10:29:20 OK 20241026095416_initial_model.sql (22.98ms)7532026/09/09 10:29:20 OK 1_commit_pending_closure.sql (5.9ms)7542026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.55ms)7552026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.05ms)7562026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.41ms)7572026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (4.09ms)7582026/09/09 10:29:20 OK 2_object_stats_trigger.sql (3.25ms)7592026/09/09 10:29:20 goose: up to current file version: 27602026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.65ms)7612026/09/09 10:29:20 goose: up to current file version: 27622026/09/09 10:29:20 OK 1_commit_pending_closure.sql (5.68ms)7632026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (5.1ms)7642026/09/09 10:29:20 OK 1_commit_pending_closure.sql (5.31ms)7652026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.94ms)7662026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.62ms)7672026/09/09 10:29:20 goose: up to current file version: 27682026/09/09 10:29:20 OK 2_object_stats_trigger.sql (3.69ms)7692026/09/09 10:29:20 goose: up to current file version: 27702026/09/09 10:29:20 OK 2_object_stats_trigger.sql (3.58ms)7712026/09/09 10:29:20 goose: up to current file version: 27722026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.26ms)7732026/09/09 10:29:20 goose: up to current file version: 27742026/09/09 10:29:20 OK 2_object_stats_trigger.sql (3.74ms)7752026/09/09 10:29:20 goose: up to current file version: 27762026/09/09 10:29:20 OK 2_object_stats_trigger.sql (3.61ms)7772026/09/09 10:29:20 goose: up to current file version: 27782026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.85ms)7792026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.92ms)7802026/09/09 10:29:20 OK 20241026095416_initial_model.sql (25.67ms)7812026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.29ms)7822026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (6.61ms)7832026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007842026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (7.85ms)7852026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200007862026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.4ms)7872026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.5ms)7882026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.69ms)7892026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.04ms)7902026/09/09 10:29:20 goose: up to current file version: 27912026/09/09 10:29:20 OK 2_object_stats_trigger.sql (3.35ms)7922026/09/09 10:29:20 goose: up to current file version: 27932026-09-09 10:29:20.725 UTC [613] ERROR: relation "goose_db_version" does not exist at character 367942026-09-09 10:29:20.725 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026-09-09 10:29:20.729 UTC [614] ERROR: relation "goose_db_version" does not exist at character 367962026-09-09 10:29:20.729 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-09-09 10:29:20.730 UTC [616] ERROR: relation "goose_db_version" does not exist at character 367982026-09-09 10:29:20.730 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-09-09 10:29:20.730 UTC [615] ERROR: relation "goose_db_version" does not exist at character 368002026-09-09 10:29:20.730 UTC [615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026-09-09 10:29:20.731 UTC [617] ERROR: relation "goose_db_version" does not exist at character 368022026-09-09 10:29:20.731 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (13.29ms)8042026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200008052026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.12ms)8062026/09/09 10:29:20 OK 2_object_stats_trigger.sql (1.99ms)8072026/09/09 10:29:20 goose: up to current file version: 28082026-09-09 10:29:20.752 UTC [618] ERROR: relation "goose_db_version" does not exist at character 368092026-09-09 10:29:20.752 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026-09-09 10:29:20.752 UTC [619] ERROR: relation "goose_db_version" does not exist at character 368112026-09-09 10:29:20.752 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026-09-09 10:29:20.752 UTC [620] ERROR: relation "goose_db_version" does not exist at character 368132026-09-09 10:29:20.752 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-09-09 10:29:20.752 UTC [621] ERROR: relation "goose_db_version" does not exist at character 368152026-09-09 10:29:20.752 UTC [621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/09/09 10:29:20 OK 20241026095416_initial_model.sql (14.12ms)8172026-09-09 10:29:20.754 UTC [622] ERROR: relation "goose_db_version" does not exist at character 368182026-09-09 10:29:20.754 UTC [622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026/09/09 10:29:20 OK 20241026095416_initial_model.sql (14.92ms)8202026/09/09 10:29:20 OK 20241026095416_initial_model.sql (15.95ms)8212026/09/09 10:29:20 OK 20241026095416_initial_model.sql (16.05ms)8222026/09/09 10:29:20 OK 20241026095416_initial_model.sql (16.19ms)8232026-09-09 10:29:20.757 UTC [623] ERROR: relation "goose_db_version" does not exist at character 368242026-09-09 10:29:20.757 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8252026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)8262026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.42ms)8272026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)8282026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)8292026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)8302026-09-09 10:29:20.759 UTC [624] ERROR: relation "goose_db_version" does not exist at character 368312026-09-09 10:29:20.759 UTC [624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026/09/09 10:29:20 OK 20251218171726_add_pins.sql (3.34ms)8332026-09-09 10:29:20.761 UTC [625] ERROR: relation "goose_db_version" does not exist at character 368342026-09-09 10:29:20.761 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC835--- PASS: TestReadRedirectKeepsNarinfoProxied (0.35s)836=== CONT TestIsValidCachePath837=== RUN TestIsValidCachePath/narinfo838=== PAUSE TestIsValidCachePath/narinfo839=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars840=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars841=== RUN TestIsValidCachePath/nar_zst842=== PAUSE TestIsValidCachePath/nar_zst843=== RUN TestIsValidCachePath/nar_xz844=== PAUSE TestIsValidCachePath/nar_xz845=== RUN TestIsValidCachePath/nar_bz2846=== PAUSE TestIsValidCachePath/nar_bz2847=== RUN TestIsValidCachePath/nar_uncompressed848=== PAUSE TestIsValidCachePath/nar_uncompressed849=== RUN TestIsValidCachePath/ls850=== PAUSE TestIsValidCachePath/ls8512026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.06ms)852=== RUN TestIsValidCachePath/log853=== PAUSE TestIsValidCachePath/log854=== RUN TestIsValidCachePath/realisation855=== PAUSE TestIsValidCachePath/realisation856=== RUN TestIsValidCachePath/nix-cache-info857=== PAUSE TestIsValidCachePath/nix-cache-info858=== RUN TestIsValidCachePath/index.html859=== PAUSE TestIsValidCachePath/index.html860=== RUN TestIsValidCachePath/traversal_parent861=== PAUSE TestIsValidCachePath/traversal_parent862=== RUN TestIsValidCachePath/traversal_in_middle863=== PAUSE TestIsValidCachePath/traversal_in_middle864=== RUN TestIsValidCachePath/invalid_char_e865=== PAUSE TestIsValidCachePath/invalid_char_e866=== RUN TestIsValidCachePath/invalid_char_u867=== PAUSE TestIsValidCachePath/invalid_char_u868=== RUN TestIsValidCachePath/random_path869=== PAUSE TestIsValidCachePath/random_path870=== RUN TestIsValidCachePath/empty871=== PAUSE TestIsValidCachePath/empty872=== RUN TestIsValidCachePath/leading_slash873=== PAUSE TestIsValidCachePath/leading_slash874=== RUN TestIsValidCachePath/wrong_extension875=== PAUSE TestIsValidCachePath/wrong_extension876=== RUN TestIsValidCachePath/short_hash877=== PAUSE TestIsValidCachePath/short_hash878=== CONT TestParseSingleRange879=== RUN TestParseSingleRange/none880=== PAUSE TestParseSingleRange/none881=== RUN TestParseSingleRange/unknown_unit882=== PAUSE TestParseSingleRange/unknown_unit883=== RUN TestParseSingleRange/multi-range_ignored884=== PAUSE TestParseSingleRange/multi-range_ignored885=== RUN TestParseSingleRange/malformed_no_dash886=== PAUSE TestParseSingleRange/malformed_no_dash887=== RUN TestParseSingleRange/malformed_both_empty888=== PAUSE TestParseSingleRange/malformed_both_empty889=== RUN TestParseSingleRange/malformed_end_before_start890=== PAUSE TestParseSingleRange/malformed_end_before_start891=== RUN TestParseSingleRange/closed892=== PAUSE TestParseSingleRange/closed893=== RUN TestParseSingleRange/open-ended894=== PAUSE TestParseSingleRange/open-ended895=== RUN TestParseSingleRange/end_clamped_to_size896=== PAUSE TestParseSingleRange/end_clamped_to_size897=== RUN TestParseSingleRange/suffix898=== PAUSE TestParseSingleRange/suffix899=== RUN TestParseSingleRange/suffix_exceeds_size900=== PAUSE TestParseSingleRange/suffix_exceeds_size901=== RUN TestParseSingleRange/single_byte902=== PAUSE TestParseSingleRange/single_byte903=== RUN TestParseSingleRange/start_past_EOF904=== PAUSE TestParseSingleRange/start_past_EOF905=== RUN TestParseSingleRange/start_far_past_EOF906=== PAUSE TestParseSingleRange/start_far_past_EOF907=== CONT TestResurrectedObjectNotDeleted9082026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.31ms)9092026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.42ms)9102026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.31ms)9112026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)9122026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009132026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.53ms)9142026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)9152026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009162026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)9172026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009182026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (7.51ms)9192026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009202026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (6.02ms)9212026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009222026/09/09 10:29:20 OK 20241026095416_initial_model.sql (12.53ms)9232026/09/09 10:29:20 OK 2_object_stats_trigger.sql (3.03ms)9242026/09/09 10:29:20 goose: up to current file version: 29252026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.66ms)9262026/09/09 10:29:20 OK 20241026095416_initial_model.sql (15.06ms)9272026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.51ms)9282026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.95ms)9292026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.47ms)9302026/09/09 10:29:20 OK 20241026095416_initial_model.sql (16.7ms)9312026/09/09 10:29:20 OK 20241026095416_initial_model.sql (16.2ms)9322026/09/09 10:29:20 OK 20241026095416_initial_model.sql (15.01ms)9332026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)9342026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.49ms)9352026/09/09 10:29:20 goose: up to current file version: 29362026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.2ms)9372026/09/09 10:29:20 goose: up to current file version: 29382026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.27ms)9392026/09/09 10:29:20 goose: up to current file version: 29402026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.39ms)9412026/09/09 10:29:20 goose: up to current file version: 29422026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)9432026/09/09 10:29:20 OK 20241026095416_initial_model.sql (13.04ms)9442026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)945--- PASS: TestReadProxyConditionalGet (0.36s)946=== CONT TestOrphanedObjectsGCStressTest9472026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)9482026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)9492026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)9502026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.46ms)9512026/09/09 10:29:20 OK 20241026095416_initial_model.sql (12.35ms)9522026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.64ms)9532026/09/09 10:29:20 OK 20241026095416_initial_model.sql (11.43ms)9542026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.55ms)9552026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.25ms)9562026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.52ms)9572026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)9582026/09/09 10:29:20 OK 20251218171726_add_pins.sql (5.26ms)9592026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)9602026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (5.59ms)9612026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009622026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.12ms)9632026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (5.75ms)9642026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009652026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (5.65ms)9662026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009672026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)9682026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009692026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)9702026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009712026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.1ms)9722026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)9732026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009742026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.62ms)9752026/09/09 10:29:20 OK 1_commit_pending_closure.sql (2.99ms)9762026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.96ms)9772026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.74ms)9782026/09/09 10:29:20 goose: up to current file version: 29792026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.1ms)9802026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.59ms)9812026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)9822026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009832026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4ms)9842026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.84ms)9852026/09/09 10:29:20 goose: up to current file version: 29862026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.46ms)9872026/09/09 10:29:20 goose: up to current file version: 29882026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.54ms)9892026/09/09 10:29:20 goose: up to current file version: 29902026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.62ms)9912026/09/09 10:29:20 goose: up to current file version: 29922026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (5.17ms)9932026/09/09 10:29:20 goose: successfully migrated database to version: 202606281200009942026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.44ms)9952026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.26ms)9962026/09/09 10:29:20 goose: up to current file version: 29972026/09/09 10:29:20 INFO Received uploads request method=POST path=/api/pending_closures9982026/09/09 10:29:20 OK 2_object_stats_trigger.sql (1.89ms)9992026/09/09 10:29:20 goose: up to current file version: 210002026/09/09 10:29:20 OK 1_commit_pending_closure.sql (4.17ms)10012026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.32ms)10022026/09/09 10:29:20 goose: up to current file version: 210032026/09/09 10:29:20 INFO Received cleanup request method=DELETE path=/api/pending_closures10042026/09/09 10:29:20 INFO Aborted multipart uploads count=010052026/09/09 10:29:20 INFO Received uploads request method=POST path=/api/pending_closures10062026-09-09 10:29:20.843 UTC [630] ERROR: relation "goose_db_version" does not exist at character 3610072026-09-09 10:29:20.843 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10082026/09/09 10:29:20 INFO Received cleanup request method=DELETE path=/api/pending_closures10092026/09/09 10:29:20 INFO Aborted multipart uploads count=110102026/09/09 10:29:20 INFO Received uploads request method=POST path=/api/pending_closures10112026/09/09 10:29:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10122026-09-09 10:29:20.861 UTC [599] ERROR: Closure does not exist: id=110132026-09-09 10:29:20.861 UTC [599] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10142026-09-09 10:29:20.861 UTC [599] STATEMENT: -- name: CommitPendingClosure :exec1015 SELECT commit_pending_closure($1::bigint)1016 1017--- PASS: TestService_cleanupPendingClosuresHandler (0.45s)1018=== CONT TestOrphanedObjectsGC10192026/09/09 10:29:20 OK 20241026095416_initial_model.sql (10.8ms)10202026-09-09 10:29:20.863 UTC [631] ERROR: relation "goose_db_version" does not exist at character 3610212026-09-09 10:29:20.863 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10222026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)10232026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.43ms)10242026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)10252026/09/09 10:29:20 goose: successfully migrated database to version: 2026062812000010262026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.28ms)10272026/09/09 10:29:20 OK 2_object_stats_trigger.sql (1.64ms)10282026/09/09 10:29:20 goose: up to current file version: 210292026/09/09 10:29:20 OK 20241026095416_initial_model.sql (11.62ms)10302026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)10312026/09/09 10:29:20 OK 20251218171726_add_pins.sql (4.35ms)1032--- PASS: TestService_healthCheckHandler (0.48s)1033=== CONT TestObjectStatsTrigger10342026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (11.43ms)10352026/09/09 10:29:20 goose: successfully migrated database to version: 2026062812000010362026/09/09 10:29:20 OK 1_commit_pending_closure.sql (3.22ms)10372026/09/09 10:29:20 OK 2_object_stats_trigger.sql (2.18ms)10382026/09/09 10:29:20 goose: up to current file version: 210392026/09/09 10:29:20 INFO Received uploads request method=POST path=/api/pending_closures10402026/09/09 10:29:20 INFO Received uploads request method=POST path=/api/pending_closures10412026/09/09 10:29:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10422026/09/09 10:29:20 INFO Received uploads request method=POST path=/api/pending_closures10432026-09-09 10:29:20.947 UTC [636] ERROR: relation "goose_db_version" does not exist at character 3610442026-09-09 10:29:20.947 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10452026/09/09 10:29:20 OK 20241026095416_initial_model.sql (9.39ms)10462026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)10472026/09/09 10:29:20 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1048--- PASS: TestService_AuthMiddleware (0.56s)1049=== CONT TestMultipartCleanup10502026/09/09 10:29:20 OK 20251218171726_add_pins.sql (3.18ms)10512026/09/09 10:29:20 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)10522026/09/09 10:29:20 goose: successfully migrated database to version: 2026062812000010532026-09-09 10:29:20.974 UTC [637] ERROR: relation "goose_db_version" does not exist at character 3610542026-09-09 10:29:20.974 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10552026/09/09 10:29:20 OK 1_commit_pending_closure.sql (1.76ms)10562026/09/09 10:29:20 OK 2_object_stats_trigger.sql (1.01ms)10572026/09/09 10:29:20 goose: up to current file version: 210582026/09/09 10:29:20 OK 20241026095416_initial_model.sql (12.45ms)10592026/09/09 10:29:20 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)10602026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.94ms)1061--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.49s)1062=== CONT TestServerTLSConfig1063=== RUN TestServerTLSConfig/no_client_CA1064=== PAUSE TestServerTLSConfig/no_client_CA1065=== RUN TestServerTLSConfig/missing_CA_file1066=== PAUSE TestServerTLSConfig/missing_CA_file1067=== RUN TestServerTLSConfig/not_a_PEM_file1068=== PAUSE TestServerTLSConfig/not_a_PEM_file1069=== CONT TestService_NativeMTLS10702026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)10712026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000010722026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.89ms)10732026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.12ms)10742026/09/09 10:29:21 goose: up to current file version: 21075--- PASS: TestReadProxyDisabled (0.52s)1076=== CONT TestMetricsInventory10772026-09-09 10:29:21.048 UTC [644] ERROR: relation "goose_db_version" does not exist at character 3610782026-09-09 10:29:21.048 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10792026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures10802026/09/09 10:29:21 OK 20241026095416_initial_model.sql (19.97ms)10812026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (4.53ms)10822026-09-09 10:29:21.085 UTC [645] ERROR: relation "goose_db_version" does not exist at character 3610832026-09-09 10:29:21.085 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10842026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.51ms)10852026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)10862026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000010872026/09/09 10:29:21 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10882026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures10892026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.33ms)1090--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.59s)1091=== CONT TestNARDeduplicationMetadataUploadBug10922026/09/09 10:29:21 OK 2_object_stats_trigger.sql (1.34ms)10932026/09/09 10:29:21 goose: up to current file version: 210942026/09/09 10:29:21 OK 20241026095416_initial_model.sql (10.35ms)10952026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)10962026-09-09 10:29:21.106 UTC [647] ERROR: relation "goose_db_version" does not exist at character 3610972026-09-09 10:29:21.106 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10982026/09/09 10:29:21 OK 20251218171726_add_pins.sql (3.79ms)1099--- PASS: TestReadProxyRangeRequest (0.68s)1100=== CONT TestCreatePendingClosureRejectsOversizedNAR11012026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures1102--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1103=== CONT TestCacheConfigHandlerMaxNarSize1104--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1105=== CONT TestGenerateLandingPage11062026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)11072026/09/09 10:29:21 goose: successfully migrated database to version: 202606281200001108--- PASS: TestGenerateLandingPage (0.00s)1109=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT11102026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.49ms)11112026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.46ms)11122026/09/09 10:29:21 goose: up to current file version: 211132026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures11142026/09/09 10:29:21 OK 20241026095416_initial_model.sql (13.07ms)11152026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (3.37ms)11162026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.04ms)11172026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (6.3ms)11182026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000011192026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.51ms)11202026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.9ms)11212026/09/09 10:29:21 goose: up to current file version: 211222026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures11232026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11242026-09-09 10:29:21.177 UTC [651] ERROR: relation "goose_db_version" does not exist at character 3611252026-09-09 10:29:21.177 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11262026/09/09 10:29:21 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmU1NjI5ZDktODljNy00NGVlLTkxMWMtOTcyYzA0ZTQzYjVhLmE4NDdkNTg1LWQ4ZTAtNDBjZi1hYzk2LTJkYjY1NGZkY2RjZXgxNzg4OTQ5NzYxMTMzMjg5MzM411272026/09/09 10:29:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmU1NjI5ZDktODljNy00NGVlLTkxMWMtOTcyYzA0ZTQzYjVhLmE4NDdkNTg1LWQ4ZTAtNDBjZi1hYzk2LTJkYjY1NGZkY2RjZXgxNzg4OTQ5NzYxMTMzMjg5MzM4 parts=11128--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.67s)1129=== CONT TestClientIntegration11302026-09-09 10:29:21.185 UTC [652] ERROR: relation "goose_db_version" does not exist at character 3611312026-09-09 10:29:21.185 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1132--- PASS: TestReadProxyInvalidPath (0.68s)1133=== CONT TestService_readinessHandler11342026/09/09 10:29:21 OK 20241026095416_initial_model.sql (11.28ms)11352026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)11362026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.44ms)11372026/09/09 10:29:21 OK 20241026095416_initial_model.sql (11.17ms)11382026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)11392026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000011402026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)11412026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.28ms)11422026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.65ms)11432026/09/09 10:29:21 OK 2_object_stats_trigger.sql (3.95ms)11442026/09/09 10:29:21 goose: up to current file version: 211452026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)11462026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000011472026/09/09 10:29:21 OK 1_commit_pending_closure.sql (11.18ms)1148--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.64s)1149=== CONT TestGCTaskStore_GetEmpty1150--- PASS: TestGCTaskStore_GetEmpty (0.00s)1151=== CONT TestCompleteMultipartUnregistered11522026/09/09 10:29:21 OK 2_object_stats_trigger.sql (3.1ms)11532026/09/09 10:29:21 goose: up to current file version: 21154--- PASS: TestReadProxyNarinfo (0.64s)1155=== CONT TestGCTaskStore_ConflictDifferentParams1156--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1157=== CONT TestGCTaskStore_DeduplicateSameParams1158--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1159=== CONT TestService_RequireScope_OIDC11602026-09-09 10:29:21.273 UTC [659] ERROR: relation "goose_db_version" does not exist at character 3611612026-09-09 10:29:21.273 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/09/09 10:29:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44125/oidc11632026-09-09 10:29:21.277 UTC [660] ERROR: relation "goose_db_version" does not exist at character 3611642026-09-09 10:29:21.277 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11652026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures11662026/09/09 10:29:21 OK 20241026095416_initial_model.sql (15.46ms)11672026/09/09 10:29:21 OK 20241026095416_initial_model.sql (18.79ms)11682026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (5.06ms)11692026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (4.32ms)11702026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.61ms)11712026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.68ms)11722026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures11732026-09-09 10:29:21.314 UTC [663] ERROR: relation "goose_db_version" does not exist at character 3611742026-09-09 10:29:21.314 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (6.09ms)11762026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000011772026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (7.37ms)11782026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000011792026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.89ms)11802026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.78ms)11812026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.18ms)11822026/09/09 10:29:21 goose: up to current file version: 211832026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.26ms)11842026/09/09 10:29:21 goose: up to current file version: 211852026/09/09 10:29:21 OK 20241026095416_initial_model.sql (11.48ms)11862026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)11872026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.8ms)1188--- PASS: TestReadProxyHead (0.83s)1189=== CONT TestGCTaskStore_StartNew1190--- PASS: TestGCTaskStore_StartNew (0.00s)1191=== CONT TestClientErrorHandling1192=== RUN TestClientErrorHandling/InvalidStorePath1193=== PAUSE TestClientErrorHandling/InvalidStorePath1194=== RUN TestClientErrorHandling/InvalidAuthToken1195=== PAUSE TestClientErrorHandling/InvalidAuthToken1196=== RUN TestClientErrorHandling/ServerNotAvailable1197=== PAUSE TestClientErrorHandling/ServerNotAvailable1198=== CONT TestGCMetrics11992026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)12002026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000012012026/09/09 10:29:21 OK 1_commit_pending_closure.sql (1.99ms)12022026/09/09 10:29:21 OK 2_object_stats_trigger.sql (972.05µs)12032026/09/09 10:29:21 goose: up to current file version: 212042026-09-09 10:29:21.360 UTC [666] ERROR: relation "goose_db_version" does not exist at character 3612052026-09-09 10:29:21.360 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1206--- PASS: TestReadProxy404 (0.85s)1207=== CONT TestClientCADerivations12082026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12092026/09/09 10:29:21 OK 20241026095416_initial_model.sql (19.64ms)12102026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (3.38ms)12112026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.03ms)12122026/09/09 10:29:21 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmU1NjI5ZDktODljNy00NGVlLTkxMWMtOTcyYzA0ZTQzYjVhLjZjYTRhZmU2LWYxOTQtNDE0Zi05ODYyLTc0ZTE5ODgyYjQ1MXgxNzg4OTQ5NzYwODY3OTQ3OTQz parts=1012132026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (6.45ms)12142026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000012152026/09/09 10:29:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12162026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.43ms)1217--- PASS: TestReadRedirectNar (0.90s)1218=== CONT TestGCBugBareHashReferences12192026/09/09 10:29:21 INFO Completed upload id=112202026/09/09 10:29:21 OK 2_object_stats_trigger.sql (4.28ms)12212026/09/09 10:29:21 goose: up to current file version: 212222026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures12232026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures12242026/09/09 10:29:21 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12252026/09/09 10:29:21 WARN Found objects in DB but missing from S3, will re-upload count=11226--- PASS: TestService_verifyS3Integrity (1.01s)1227=== CONT TestCacheStatsHandler1228--- PASS: TestService_Rustfstest (0.92s)1229=== CONT TestResolveDBConnectionString1230=== RUN TestResolveDBConnectionString/flag_wins1231=== PAUSE TestResolveDBConnectionString/flag_wins1232=== RUN TestResolveDBConnectionString/file_when_flag_empty1233=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1234=== RUN TestResolveDBConnectionString/missing_file_is_an_error1235=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1236=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1237=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1238=== RUN TestResolveDBConnectionString/nothing_configured1239=== PAUSE TestResolveDBConnectionString/nothing_configured1240=== CONT TestCacheConfigHandler1241=== RUN TestCacheConfigHandler/full_config,_no_issuer1242=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1243=== RUN TestCacheConfigHandler/no_cache_url_configured1244=== PAUSE TestCacheConfigHandler/no_cache_url_configured1245=== RUN TestCacheConfigHandler/no_signing_keys1246=== PAUSE TestCacheConfigHandler/no_signing_keys1247=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1248=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1249=== CONT TestPinProtectsFromGC12502026-09-09 10:29:21.443 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612512026-09-09 10:29:21.443 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12522026/09/09 10:29:21 OK 20241026095416_initial_model.sql (15.02ms)12532026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)12542026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12552026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.78ms)12562026-09-09 10:29:21.476 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3612572026-09-09 10:29:21.476 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12582026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)12592026/09/09 10:29:21 goose: successfully migrated database to version: 202606281200001260--- PASS: TestReadRedirectUsesPublicS3URL (0.97s)1261=== CONT TestService_ReadScope_PublicByDefault12622026/09/09 10:29:21 OK 1_commit_pending_closure.sql (17.52ms)12632026/09/09 10:29:21 OK 2_object_stats_trigger.sql (3.36ms)12642026/09/09 10:29:21 goose: up to current file version: 212652026/09/09 10:29:21 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmU1NjI5ZDktODljNy00NGVlLTkxMWMtOTcyYzA0ZTQzYjVhLjA5YzAxNDk1LTM1OWQtNGZjMC05ZDA2LTQxZDQ1MWI0NDdmYXgxNzg4OTQ5NzYwOTUzOTI4NzA3 parts=1012662026/09/09 10:29:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12672026/09/09 10:29:21 INFO Completed upload id=112682026/09/09 10:29:21 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012692026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures1270--- PASS: TestReadProxyNarStreaming (0.99s)1271=== CONT TestClientWithDependencies12722026/09/09 10:29:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures12732026-09-09 10:29:21.512 UTC [697] ERROR: relation "goose_db_version" does not exist at character 3612742026-09-09 10:29:21.512 UTC [697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12752026/09/09 10:29:21 OK 20241026095416_initial_model.sql (15.43ms)12762026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)12772026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.69ms)12782026-09-09 10:29:21.522 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3612792026-09-09 10:29:21.522 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12802026/09/09 10:29:21 INFO Aborted multipart uploads count=012812026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.72ms)12822026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000012832026-09-09 10:29:21.528 UTC [702] ERROR: relation "goose_db_version" does not exist at character 3612842026-09-09 10:29:21.528 UTC [702] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12852026/09/09 10:29:21 OK 20241026095416_initial_model.sql (12.67ms)12862026/09/09 10:29:21 OK 1_commit_pending_closure.sql (5.25ms)12872026/09/09 10:29:21 OK 2_object_stats_trigger.sql (1.86ms)12882026/09/09 10:29:21 goose: up to current file version: 212892026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)12902026/09/09 10:29:21 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=012912026/09/09 10:29:21 INFO Vacuumed table table=pending_closures12922026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.59ms)12932026/09/09 10:29:21 OK 20241026095416_initial_model.sql (14.69ms)12942026/09/09 10:29:21 INFO Vacuumed table table=pending_objects12952026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.57ms)12962026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000012972026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (4.51ms)12982026/09/09 10:29:21 INFO Vacuumed table table=multipart_uploads12992026/09/09 10:29:21 OK 1_commit_pending_closure.sql (4.69ms)13002026/09/09 10:29:21 OK 20241026095416_initial_model.sql (15.67ms)13012026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.33ms)13022026/09/09 10:29:21 goose: up to current file version: 213032026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.05ms)13042026/09/09 10:29:21 INFO Vacuumed table table=closures13052026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (3.95ms)13062026/09/09 10:29:21 INFO Vacuumed table table=objects13072026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)13082026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000013092026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.55ms)13102026/09/09 10:29:21 OK 1_commit_pending_closure.sql (2.79ms)13112026/09/09 10:29:21 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001312--- PASS: TestService_createPendingClosureHandler (1.15s)1313=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13142026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.15ms)13152026/09/09 10:29:21 goose: up to current file version: 213162026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)13172026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000013182026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.61ms)13192026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.14ms)13202026/09/09 10:29:21 goose: up to current file version: 213212026-09-09 10:29:21.572 UTC [704] ERROR: relation "goose_db_version" does not exist at character 3613222026-09-09 10:29:21.572 UTC [704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13232026/09/09 10:29:21 OK 20241026095416_initial_model.sql (11.87ms)13242026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)1325--- PASS: TestResurrectedObjectNotDeleted (0.83s)1326=== CONT TestClientMultipleUploads13272026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.23ms)13282026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)13292026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000013302026-09-09 10:29:21.602 UTC [707] ERROR: relation "goose_db_version" does not exist at character 3613312026-09-09 10:29:21.602 UTC [707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13322026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.11ms)13332026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.44ms)13342026/09/09 10:29:21 goose: up to current file version: 213352026/09/09 10:29:21 OK 20241026095416_initial_model.sql (14.98ms)13362026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (3.94ms)13372026/09/09 10:29:21 OK 20251218171726_add_pins.sql (6.64ms)13382026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (7.21ms)13392026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000013402026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.5ms)13412026/09/09 10:29:21 OK 2_object_stats_trigger.sql (1.99ms)13422026/09/09 10:29:21 goose: up to current file version: 213432026-09-09 10:29:21.661 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3613442026-09-09 10:29:21.661 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13452026/09/09 10:29:21 OK 20241026095416_initial_model.sql (16.12ms)13462026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (6.83ms)13472026-09-09 10:29:21.694 UTC [710] ERROR: relation "goose_db_version" does not exist at character 3613482026-09-09 10:29:21.694 UTC [710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1349--- PASS: TestObjectStatsTrigger (0.80s)1350=== CONT TestService_AuthMiddleware_OIDC13512026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.59ms)13522026/09/09 10:29:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44741/oidc13532026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)13542026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000013552026/09/09 10:29:21 OK 1_commit_pending_closure.sql (3.04ms)13562026/09/09 10:29:21 OK 2_object_stats_trigger.sql (1.79ms)13572026/09/09 10:29:21 goose: up to current file version: 213582026/09/09 10:29:21 OK 20241026095416_initial_model.sql (10.8ms)13592026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures13602026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)13612026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.57ms)13622026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)13632026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000013642026/09/09 10:29:21 OK 1_commit_pending_closure.sql (2.89ms)13652026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.29ms)13662026/09/09 10:29:21 goose: up to current file version: 213672026/09/09 10:29:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13682026/09/09 10:29:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1369--- PASS: TestService_NativeMTLS (0.74s)1370=== CONT TestService_ReadAuthMiddleware13712026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13722026-09-09 10:29:21.789 UTC [715] ERROR: relation "goose_db_version" does not exist at character 3613732026-09-09 10:29:21.789 UTC [715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1374--- PASS: TestMetricsInventory (0.78s)1375=== CONT TestService_AuthMiddleware_MTLSProxyHeader13762026/09/09 10:29:21 OK 20241026095416_initial_model.sql (12.86ms)13772026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)13782026/09/09 10:29:21 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmU1NjI5ZDktODljNy00NGVlLTkxMWMtOTcyYzA0ZTQzYjVhLmMyYjI3OTJmLTkyZWEtNDRhMS1iNWJmLTBlYWRiOWFiYzlkYXgxNzg4OTQ5NzYxMTcwMjc1MTE4 parts=1213792026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures13802026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.77ms)1381--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.31s)1382=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13832026/09/09 10:29:21 INFO Received uploads request method=POST path=/1384=== CONT TestProxyWriteTimeout/narinfo1385=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13862026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/1387=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13882026/09/09 10:29:21 INFO Received request for more parts method=POST path=/1389=== CONT TestProxyWriteTimeout/unknown_size1390=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13912026/09/09 10:29:21 INFO Received uploads request method=POST path=/1392--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1393 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1394 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1395 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1396 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1397=== CONT TestProxyWriteTimeout/10_GiB_nar1398=== CONT TestProxyWriteTimeout/1_GiB_nar1399--- PASS: TestProxyWriteTimeout (0.00s)1400 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1401 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1402 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1403 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1404=== CONT TestIsValidUploadKey/narinfo1405=== CONT TestIsValidUploadKey/realisation_plus_in_output1406=== CONT TestIsValidUploadKey/unknown_type1407=== CONT TestIsValidUploadKey/empty_key1408=== CONT TestIsValidUploadKey/absolute1409=== CONT TestIsValidUploadKey/traversal_nar1410=== CONT TestIsValidUploadKey/traversal1411=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1412=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1413=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1414=== CONT TestIsValidUploadKey/index.html1415=== CONT TestIsValidUploadKey/nix-cache-info1416=== CONT TestIsValidUploadKey/build_log_home-manager_file1417=== CONT TestIsValidUploadKey/realisation1418=== CONT TestIsValidUploadKey/build_log_equals1419=== CONT TestIsValidUploadKey/build_log_question_mark1420=== CONT TestIsValidUploadKey/build_log_plus_in_name1421=== CONT TestIsValidUploadKey/nar_plain1422=== CONT TestIsValidUploadKey/build_log1423=== CONT TestIsValidUploadKey/listing1424=== CONT TestIsValidUploadKey/nar_zst1425=== CONT TestIsValidUploadKey/nar_xz1426--- PASS: TestIsValidUploadKey (0.10s)1427 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1428 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1429 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1430 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1431 --- PASS: TestIsValidUploadKey/absolute (0.00s)1432 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1433 --- PASS: TestIsValidUploadKey/traversal (0.00s)1434 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1435 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1436 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1437 --- PASS: TestIsValidUploadKey/index.html (0.00s)1438 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1439 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1440 --- PASS: TestIsValidUploadKey/realisation (0.00s)1441 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1442 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1443 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1444 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1445 --- PASS: TestIsValidUploadKey/build_log (0.00s)1446 --- PASS: TestIsValidUploadKey/listing (0.00s)1447 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1448 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1449=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14502026/09/09 10:29:21 INFO Received request for more parts method=POST path=/14512026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)14522026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000014532026/09/09 10:29:21 OK 1_commit_pending_closure.sql (10.84ms)14542026/09/09 10:29:21 INFO Received cleanup request method=DELETE path=/api/pending_closures14552026/09/09 10:29:21 OK 2_object_stats_trigger.sql (3ms)14562026/09/09 10:29:21 goose: up to current file version: 214572026/09/09 10:29:21 INFO Aborted multipart uploads count=114582026-09-09 10:29:21.844 UTC [719] ERROR: relation "goose_db_version" does not exist at character 3614592026-09-09 10:29:21.844 UTC [719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1460--- PASS: TestMultipartCleanup (0.88s)1461=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14622026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/14632026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures1464=== NAME TestNARDeduplicationMetadataUploadBug1465 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2198884472/001/store/s0p7g5m2mdmh26lgadlfwsgg26yvn1iw-file1.txt14662026/09/09 10:29:21 OK 20241026095416_initial_model.sql (13.06ms)1467--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.75s)1468=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14692026/09/09 10:29:21 INFO Received uploads request method=POST path=/14702026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)14712026/09/09 10:29:21 OK 20251218171726_add_pins.sql (4.53ms)14722026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)14732026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000014742026/09/09 10:29:21 OK 1_commit_pending_closure.sql (2.56ms)14752026/09/09 10:29:21 OK 2_object_stats_trigger.sql (1.09ms)14762026/09/09 10:29:21 goose: up to current file version: 214772026-09-09 10:29:21.889 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3614782026-09-09 10:29:21.889 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14792026/09/09 10:29:21 WARN readiness check failed error="closed pool"1480--- PASS: TestService_readinessHandler (0.70s)1481=== CONT TestIsValidCachePath/narinfo1482=== CONT TestIsValidCachePath/short_hash1483=== CONT TestIsValidCachePath/wrong_extension1484=== CONT TestIsValidCachePath/leading_slash1485=== CONT TestIsValidCachePath/empty1486=== CONT TestIsValidCachePath/random_path1487=== CONT TestIsValidCachePath/invalid_char_u1488=== CONT TestIsValidCachePath/invalid_char_e1489=== CONT TestIsValidCachePath/traversal_in_middle1490=== CONT TestIsValidCachePath/traversal_parent1491=== CONT TestIsValidCachePath/index.html1492=== CONT TestIsValidCachePath/nix-cache-info1493=== CONT TestIsValidCachePath/realisation1494=== CONT TestIsValidCachePath/log1495=== CONT TestIsValidCachePath/ls1496=== CONT TestIsValidCachePath/nar_uncompressed1497=== CONT TestIsValidCachePath/nar_bz21498=== CONT TestIsValidCachePath/nar_xz1499=== CONT TestIsValidCachePath/nar_zst1500=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1501--- PASS: TestIsValidCachePath (0.00s)1502 --- PASS: TestIsValidCachePath/narinfo (0.00s)1503 --- PASS: TestIsValidCachePath/short_hash (0.00s)1504 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1505 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1506 --- PASS: TestIsValidCachePath/empty (0.00s)1507 --- PASS: TestIsValidCachePath/random_path (0.00s)1508 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1509 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1510 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1511 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1512 --- PASS: TestIsValidCachePath/index.html (0.00s)1513 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1514 --- PASS: TestIsValidCachePath/realisation (0.00s)1515 --- PASS: TestIsValidCachePath/log (0.00s)1516 --- PASS: TestIsValidCachePath/ls (0.00s)1517 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1518 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1519 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1520 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1521 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1522=== CONT TestParseSingleRange/none1523=== CONT TestParseSingleRange/start_far_past_EOF1524=== CONT TestParseSingleRange/start_past_EOF1525=== CONT TestParseSingleRange/single_byte1526=== CONT TestParseSingleRange/suffix_exceeds_size1527=== CONT TestParseSingleRange/suffix1528=== CONT TestParseSingleRange/end_clamped_to_size1529=== CONT TestParseSingleRange/open-ended1530=== CONT TestParseSingleRange/closed1531=== CONT TestParseSingleRange/malformed_end_before_start1532=== CONT TestParseSingleRange/malformed_both_empty1533=== CONT TestParseSingleRange/malformed_no_dash1534=== CONT TestParseSingleRange/multi-range_ignored1535=== CONT TestParseSingleRange/unknown_unit1536--- PASS: TestParseSingleRange (0.00s)1537 --- PASS: TestParseSingleRange/none (0.00s)1538 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1539 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1540 --- PASS: TestParseSingleRange/single_byte (0.00s)1541 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1542 --- PASS: TestParseSingleRange/suffix (0.00s)1543 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1544 --- PASS: TestParseSingleRange/open-ended (0.00s)1545 --- PASS: TestParseSingleRange/closed (0.00s)1546 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1547 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1548 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1549 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1550 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1551=== CONT TestServerTLSConfig/no_client_CA1552=== CONT TestServerTLSConfig/missing_CA_file1553=== CONT TestServerTLSConfig/not_a_PEM_file1554--- PASS: TestServerTLSConfig (0.00s)1555 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1556 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1557 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1558=== CONT TestClientErrorHandling/InvalidStorePath15592026/09/09 10:29:21 OK 20241026095416_initial_model.sql (8.5ms)15602026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)15612026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.05ms)15622026/09/09 10:29:21 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)15632026/09/09 10:29:21 goose: successfully migrated database to version: 2026062812000015642026/09/09 10:29:21 OK 1_commit_pending_closure.sql (2.16ms)15652026/09/09 10:29:21 OK 2_object_stats_trigger.sql (2.4ms)15662026/09/09 10:29:21 goose: up to current file version: 215672026/09/09 10:29:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15682026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15692026/09/09 10:29:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1570=== CONT TestClientErrorHandling/ServerNotAvailable15712026/09/09 10:29:21 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1572--- PASS: TestCompleteMultipartUnregistered (0.73s)1573=== CONT TestClientErrorHandling/InvalidAuthToken1574=== CONT TestResolveDBConnectionString/flag_wins1575=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1576=== CONT TestResolveDBConnectionString/nothing_configured1577=== CONT TestResolveDBConnectionString/missing_file_is_an_error1578=== CONT TestResolveDBConnectionString/file_when_flag_empty1579=== CONT TestCacheConfigHandler/full_config,_no_issuer1580=== CONT TestCacheConfigHandler/no_signing_keys1581=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1582=== CONT TestCacheConfigHandler/no_cache_url_configured1583--- PASS: TestCacheConfigHandler (0.00s)1584 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1585 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1586 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1587 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1588--- PASS: TestResolveDBConnectionString (0.00s)1589 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1590 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1591 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1592 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1593 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)15942026/09/09 10:29:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmU1NjI5ZDktODljNy00NGVlLTkxMWMtOTcyYzA0ZTQzYjVhLjM5ZDFhMDRmLWFjMWMtNDE0My05OTBjLTY0NGMyNzc2ZTEyY3gxNzg4OTQ5NzYxMzA0MDU5MTE0 parts=121595--- PASS: TestRedundantMultipartUpload (1.45s)15962026/09/09 10:29:21 INFO Received uploads request method=POST path=/api/pending_closures15972026-09-09 10:29:21.971 UTC [813] ERROR: relation "goose_db_version" does not exist at character 3615982026-09-09 10:29:21.971 UTC [813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1599=== NAME TestClientIntegration1600 client_integration_test.go:277: Created store path: /build/TestClientIntegration1367225368/002/store/r8k83ykchsvpav77dvg1n4ak48qz5y3c-test-file.txt16012026/09/09 10:29:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16022026/09/09 10:29:21 INFO Uploading s0p7g5m2mdmh26lgadlfwsgg26yvn1iw-file1.txt (160B)16032026/09/09 10:29:21 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1604=== NAME TestOrphanedObjectsGC1605 orphaned_objects_gc_test.go:290: GC Test Summary:1606 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1607 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1608 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1609 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1610 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1611--- PASS: TestOrphanedObjectsGC (1.13s)16122026/09/09 10:29:21 OK 20241026095416_initial_model.sql (11.49ms)16132026/09/09 10:29:21 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)16142026/09/09 10:29:21 WARN Failed to register uploaded object key=s0p7g5m2mdmh26lgadlfwsgg26yvn1iw.ls error="server returned 404: 404 page not found\n"16152026/09/09 10:29:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16162026/09/09 10:29:21 INFO Signed narinfos id=1 count=116172026/09/09 10:29:21 INFO Uploading 1 narinfos16182026/09/09 10:29:21 OK 20251218171726_add_pins.sql (5.05ms)16192026/09/09 10:29:22 WARN Failed to register uploaded object key=s0p7g5m2mdmh26lgadlfwsgg26yvn1iw.narinfo error="server returned 404: 404 page not found\n"16202026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16212026/09/09 10:29:22 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)16222026/09/09 10:29:22 goose: successfully migrated database to version: 2026062812000016232026/09/09 10:29:22 OK 1_commit_pending_closure.sql (3.26ms)16242026/09/09 10:29:22 OK 2_object_stats_trigger.sql (2.82ms)16252026/09/09 10:29:22 goose: up to current file version: 216262026/09/09 10:29:22 INFO Completed upload id=116272026/09/09 10:29:22 INFO Upload complete. (111ms)1628=== NAME TestNARDeduplicationMetadataUploadBug1629 metadata_upload_test.go:54: Retrieved narinfo from S3:1630 StorePath: /build/TestNARDeduplicationMetadataUploadBug2198884472/001/store/s0p7g5m2mdmh26lgadlfwsgg26yvn1iw-file1.txt1631 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1632 Compression: zstd1633 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1634 NarSize: 1601635 References: 1636 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1637 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1638 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1639 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16402026/09/09 10:29:22 INFO Aborted multipart uploads count=01641=== RUN TestService_RequireScope_OIDC/builder_may_write1642=== PAUSE TestService_RequireScope_OIDC/builder_may_write1643=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1644=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1645=== RUN TestService_RequireScope_OIDC/ops_may_admin1646=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1647=== RUN TestService_RequireScope_OIDC/ops_may_not_write1648=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1649=== RUN TestService_RequireScope_OIDC/reader_may_not_write1650=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1651=== RUN TestService_RequireScope_OIDC/static_token_may_admin1652=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1653=== RUN TestService_RequireScope_OIDC/static_token_may_write1654=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1655=== RUN TestService_RequireScope_OIDC/reader_may_read1656=== PAUSE TestService_RequireScope_OIDC/reader_may_read1657=== RUN TestService_RequireScope_OIDC/writer_implies_read1658=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1659=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1660=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1661=== CONT TestService_RequireScope_OIDC/builder_may_write1662=== CONT TestService_RequireScope_OIDC/static_token_may_write1663=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1664=== CONT TestService_RequireScope_OIDC/ops_may_not_write1665=== CONT TestService_RequireScope_OIDC/writer_implies_read1666=== CONT TestService_RequireScope_OIDC/reader_may_read16672026/09/09 10:29:22 WARN Force mode enabled - objects will be deleted immediately without grace period16682026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[admin]1669=== CONT TestService_RequireScope_OIDC/static_token_may_admin16702026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[write]1671=== CONT TestService_RequireScope_OIDC/reader_may_not_write16722026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[write]1673=== CONT TestService_RequireScope_OIDC/ops_may_admin16742026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[read]1675=== CONT TestService_RequireScope_OIDC/builder_may_not_admin16762026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[read]16772026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[admin]16782026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[write]1679--- PASS: TestService_RequireScope_OIDC (0.76s)1680 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1681 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1682 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1683 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1684 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1685 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1686 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1687 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1688 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1689 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)16902026/09/09 10:29:22 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=016912026/09/09 10:29:22 INFO Vacuumed table table=pending_closures16922026/09/09 10:29:22 INFO Vacuumed table table=pending_objects16932026/09/09 10:29:22 INFO Vacuumed table table=multipart_uploads16942026/09/09 10:29:22 INFO Vacuumed table table=closures16952026/09/09 10:29:22 INFO Vacuumed table table=objects16962026-09-09 10:29:22.037 UTC [863] ERROR: relation "goose_db_version" does not exist at character 3616972026-09-09 10:29:22.037 UTC [863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1698--- PASS: TestGCMetrics (0.70s)16992026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17002026/09/09 10:29:22 OK 20241026095416_initial_model.sql (12.55ms)1701=== NAME TestNARDeduplicationMetadataUploadBug1702 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2198884472/001/store/nbd9j0qz6y0pd0zc6zz8assfjh24ihd4-file2.txt17032026/09/09 10:29:22 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)17042026/09/09 10:29:22 OK 20251218171726_add_pins.sql (5.16ms)17052026/09/09 10:29:22 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)17062026/09/09 10:29:22 goose: successfully migrated database to version: 2026062812000017072026/09/09 10:29:22 OK 1_commit_pending_closure.sql (2.69ms)17082026/09/09 10:29:22 OK 2_object_stats_trigger.sql (1.28ms)17092026/09/09 10:29:22 goose: up to current file version: 217102026/09/09 10:29:22 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17112026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures17122026/09/09 10:29:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17132026/09/09 10:29:22 INFO Uploading r8k83ykchsvpav77dvg1n4ak48qz5y3c-test-file.txt (152B)17142026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17152026/09/09 10:29:22 WARN Failed to register uploaded object key=r8k83ykchsvpav77dvg1n4ak48qz5y3c.ls error="server returned 404: 404 page not found\n"17162026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17172026/09/09 10:29:22 INFO Signed narinfos id=1 count=117182026/09/09 10:29:22 INFO Uploading 1 narinfos17192026/09/09 10:29:22 WARN Failed to register uploaded object key=r8k83ykchsvpav77dvg1n4ak48qz5y3c.narinfo error="server returned 404: 404 page not found\n"17202026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1721--- PASS: TestCacheStatsHandler (0.69s)17222026/09/09 10:29:22 INFO Completed upload id=117232026/09/09 10:29:22 INFO Upload complete. (109ms)1724=== NAME TestClientIntegration1725 client_integration_test.go:293: Retrieved narinfo from S3:1726 StorePath: /build/TestClientIntegration1367225368/002/store/r8k83ykchsvpav77dvg1n4ak48qz5y3c-test-file.txt1727 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1728 Compression: zstd1729 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11730 NarSize: 1521731 References: 1732 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11733 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1734 client_integration_test.go:294: Decompressed .ls content (64 bytes):1735 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1736 client_integration_test.go:297: Testing garbage collection...17372026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1738=== NAME TestClientCADerivations1739 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2679512592/001/store/w0csrkjyvsbkml8zg58zww6ji2w42l86-ca-test17402026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures17412026/09/09 10:29:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures17422026/09/09 10:29:22 INFO Garbage collection started17432026/09/09 10:29:22 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17442026/09/09 10:29:22 WARN Failed to register uploaded object key=nbd9j0qz6y0pd0zc6zz8assfjh24ihd4.ls error="server returned 404: 404 page not found\n"17452026/09/09 10:29:22 INFO Aborted multipart uploads count=017462026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17472026/09/09 10:29:22 INFO Signed narinfos id=2 count=117482026/09/09 10:29:22 INFO Uploading 1 narinfos17492026/09/09 10:29:22 WARN Force mode enabled - objects will be deleted immediately without grace period1750--- PASS: TestService_ReadScope_PublicByDefault (0.69s)17512026/09/09 10:29:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.860887ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17522026/09/09 10:29:22 WARN Failed to register uploaded object key=nbd9j0qz6y0pd0zc6zz8assfjh24ihd4.narinfo error="server returned 404: 404 page not found\n"17532026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17542026/09/09 10:29:22 INFO Completed upload id=217552026/09/09 10:29:22 INFO Upload complete. (88ms)1756=== NAME TestNARDeduplicationMetadataUploadBug1757 metadata_upload_test.go:76: Retrieved narinfo from S3:1758 StorePath: /build/TestNARDeduplicationMetadataUploadBug2198884472/001/store/nbd9j0qz6y0pd0zc6zz8assfjh24ihd4-file2.txt1759 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1760 Compression: zstd1761 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1762 NarSize: 1601763 References: 1764 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1765=== NAME TestClientCADerivations1766 client_ca_test.go:139: Found 1 dependencies (including self)1767=== NAME TestNARDeduplicationMetadataUploadBug1768 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1769 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1770 {"version":1,"root":{"type":"regular","size":44}}1771--- PASS: TestNARDeduplicationMetadataUploadBug (1.09s)1772=== NAME TestPinProtectsFromGC1773 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC1694275365/001/store/6hfbgavyp1nw6r6xkmh5dd1q6xj5qsp1-pinned-file.txt1774 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC1694275365/001/store/r0fq888l1yqzl8cp2nl4b6zdzsi1bx2s-unpinned-file.txt17752026/09/09 10:29:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17762026/09/09 10:29:22 WARN mTLS auth: bound subjects configured but subject DN unavailable17772026/09/09 10:29:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1778--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.67s)1779=== NAME TestClientWithDependencies1780 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies2243131906/001/store/fdbc9373gw0jq3sykd1kdzzml19pxij8-test-script17812026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17822026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1783--- PASS: TestGCBugBareHashReferences (0.90s)1784=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1785=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1786=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1787=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1788=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1789=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1790=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1791=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1792=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1793=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1794=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1795=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured17962026/09/09 10:29:22 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]17972026/09/09 10:29:22 WARN Authentication failed token_preview=eyJhbGciOi...HULWnWT_6g token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]17982026/09/09 10:29:22 INFO OIDC auth successful provider=test scopes=[write]1799--- PASS: TestService_AuthMiddleware_OIDC (0.61s)1800 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1801 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1802 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1803 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1804=== NAME TestClientWithDependencies1805 client_integration_test.go:596: Found 1 dependencies (including self)18062026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures1807=== NAME TestClientMultipleUploads1808 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads1842494997/001/store/cgr1bmcpvyl5qvk5gjz4gj74zjr6ns7n-test-file-0.txt18092026/09/09 10:29:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18102026/09/09 10:29:22 INFO Uploading w0csrkjyvsbkml8zg58zww6ji2w42l86-ca-test (144B)1811--- PASS: TestService_ReadAuthMiddleware (0.59s)18122026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures18132026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18142026/09/09 10:29:22 WARN Failed to register uploaded object key=log/z22q631j37rpxcmzzqsfyk7qd5dd790g-ca-test.drv error="server returned 404: 404 page not found\n"18152026/09/09 10:29:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18162026/09/09 10:29:22 INFO Uploading 6hfbgavyp1nw6r6xkmh5dd1q6xj5qsp1-pinned-file.txt (128B)18172026/09/09 10:29:22 WARN Failed to register uploaded object key=w0csrkjyvsbkml8zg58zww6ji2w42l86.ls error="server returned 404: 404 page not found\n"18182026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18192026/09/09 10:29:22 INFO Signed narinfos id=1 count=118202026/09/09 10:29:22 INFO Uploading 1 narinfos18212026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18222026/09/09 10:29:22 WARN Failed to register uploaded object key=w0csrkjyvsbkml8zg58zww6ji2w42l86.narinfo error="server returned 404: 404 page not found\n"18232026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18242026/09/09 10:29:22 WARN Failed to register uploaded object key=6hfbgavyp1nw6r6xkmh5dd1q6xj5qsp1.ls error="server returned 404: 404 page not found\n"18252026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18262026/09/09 10:29:22 INFO Signed narinfos id=1 count=118272026/09/09 10:29:22 INFO Uploading 1 narinfos1828=== NAME TestClientMultipleUploads1829 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads1842494997/001/store/i7dr8hd5y03qirzks4fs8xln7r7lvvsm-test-file-1.txt18302026/09/09 10:29:22 INFO Completed upload id=118312026/09/09 10:29:22 INFO Upload complete. (129ms)18322026/09/09 10:29:22 WARN Failed to register uploaded object key=6hfbgavyp1nw6r6xkmh5dd1q6xj5qsp1.narinfo error="server returned 404: 404 page not found\n"18332026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1834=== NAME TestClientCADerivations1835 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2679512592/001/store/w0csrkjyvsbkml8zg58zww6ji2w42l86-ca-test1836 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1837 Compression: zstd1838 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1839 NarSize: 1441840 References: 1841 Deriver: /build/TestClientCADerivations2679512592/001/store/z22q631j37rpxcmzzqsfyk7qd5dd790g-ca-test.drv1842 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1843 client_ca_test.go:185: Checking for realisation files in S3...1844--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.56s)1845=== NAME TestClientCADerivations1846 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1847 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18482026/09/09 10:29:22 INFO Completed upload id=118492026/09/09 10:29:22 INFO Upload complete. (110ms)18502026/09/09 10:29:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=429.226841ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18512026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18522026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures1853=== NAME TestClientMultipleUploads1854 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads1842494997/001/store/6j2i44swzks3grnmfkh3fpv9yg1s8max-test-file-2.txt18552026/09/09 10:29:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18562026/09/09 10:29:22 INFO Uploading fdbc9373gw0jq3sykd1kdzzml19pxij8-test-script (136B)18572026/09/09 10:29:22 WARN Failed to register uploaded object key=log/2q2xsp9hxb0jc217bkjww9xcgaq9hjjv-test-script.drv error="server returned 404: 404 page not found\n"18582026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18592026/09/09 10:29:22 WARN Failed to register uploaded object key=fdbc9373gw0jq3sykd1kdzzml19pxij8.ls error="server returned 404: 404 page not found\n"18602026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18612026/09/09 10:29:22 INFO Signed narinfos id=1 count=118622026/09/09 10:29:22 INFO Uploading 1 narinfos18632026/09/09 10:29:22 WARN Failed to register uploaded object key=fdbc9373gw0jq3sykd1kdzzml19pxij8.narinfo error="server returned 404: 404 page not found\n"18642026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18652026/09/09 10:29:22 INFO Completed upload id=118662026/09/09 10:29:22 INFO Upload complete. (67ms)1867=== NAME TestClientWithDependencies1868 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2243131906/001/store) requires matching store prefix1869--- PASS: TestClientWithDependencies (0.93s)18702026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18712026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18722026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures18732026/09/09 10:29:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18742026/09/09 10:29:22 INFO Uploading r0fq888l1yqzl8cp2nl4b6zdzsi1bx2s-unpinned-file.txt (128B)18752026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18762026/09/09 10:29:22 WARN Failed to register uploaded object key=r0fq888l1yqzl8cp2nl4b6zdzsi1bx2s.ls error="server returned 404: 404 page not found\n"18772026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18782026/09/09 10:29:22 INFO Signed narinfos id=2 count=118792026/09/09 10:29:22 INFO Uploading 1 narinfos18802026/09/09 10:29:22 WARN Failed to register uploaded object key=r0fq888l1yqzl8cp2nl4b6zdzsi1bx2s.narinfo error="server returned 404: 404 page not found\n"18812026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18822026/09/09 10:29:22 INFO Completed upload id=218832026/09/09 10:29:22 INFO Upload complete. (92ms)18842026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures18852026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures18862026/09/09 10:29:22 INFO Received uploads request method=POST path=/api/pending_closures1887=== NAME TestClientCADerivations1888 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1889 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1890 error: binary cache 's3://bucket40?endpoint=http://localhost:36721®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2679512592/001/store'1891 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 118922026/09/09 10:29:22 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18932026/09/09 10:29:22 INFO Uploading cgr1bmcpvyl5qvk5gjz4gj74zjr6ns7n-test-file-0.txt (160B)18942026/09/09 10:29:22 INFO Uploading i7dr8hd5y03qirzks4fs8xln7r7lvvsm-test-file-1.txt (160B)18952026/09/09 10:29:22 INFO Uploading 6j2i44swzks3grnmfkh3fpv9yg1s8max-test-file-2.txt (160B)1896--- PASS: TestClientCADerivations (1.15s)18972026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18982026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18992026/09/09 10:29:22 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19002026/09/09 10:29:22 WARN Failed to register uploaded object key=6j2i44swzks3grnmfkh3fpv9yg1s8max.ls error="server returned 404: 404 page not found\n"19012026/09/09 10:29:22 WARN Failed to register uploaded object key=i7dr8hd5y03qirzks4fs8xln7r7lvvsm.ls error="server returned 404: 404 page not found\n"19022026/09/09 10:29:22 WARN Failed to register uploaded object key=cgr1bmcpvyl5qvk5gjz4gj74zjr6ns7n.ls error="server returned 404: 404 page not found\n"19032026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19042026/09/09 10:29:22 INFO Signed narinfos id=1 count=119052026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19062026/09/09 10:29:22 INFO Signed narinfos id=2 count=119072026/09/09 10:29:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign19082026/09/09 10:29:22 INFO Signed narinfos id=3 count=119092026/09/09 10:29:22 INFO Uploading 3 narinfos19102026/09/09 10:29:22 WARN Failed to register uploaded object key=i7dr8hd5y03qirzks4fs8xln7r7lvvsm.narinfo error="server returned 404: 404 page not found\n"19112026/09/09 10:29:22 WARN Failed to register uploaded object key=6j2i44swzks3grnmfkh3fpv9yg1s8max.narinfo error="server returned 404: 404 page not found\n"19122026/09/09 10:29:22 WARN Failed to register uploaded object key=cgr1bmcpvyl5qvk5gjz4gj74zjr6ns7n.narinfo error="server returned 404: 404 page not found\n"19132026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19142026/09/09 10:29:22 INFO Completed upload id=119152026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19162026/09/09 10:29:22 INFO Completed upload id=219172026/09/09 10:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete19182026/09/09 10:29:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19192026/09/09 10:29:22 INFO Completed upload id=319202026/09/09 10:29:22 INFO Upload complete. (113ms)1921=== NAME TestClientMultipleUploads1922 client_integration_test.go:350: Uploaded 3 paths in 150.092657ms1923--- PASS: TestClientMultipleUploads (0.97s)19242026/09/09 10:29:22 INFO Received create pin request method=POST path=/api/pins/myapp19252026/09/09 10:29:22 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1694275365/001/store/6hfbgavyp1nw6r6xkmh5dd1q6xj5qsp1-pinned-file.txt narinfo_key=6hfbgavyp1nw6r6xkmh5dd1q6xj5qsp1.narinfo19262026/09/09 10:29:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures19272026/09/09 10:29:22 INFO Garbage collection started19282026/09/09 10:29:22 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19292026/09/09 10:29:22 INFO Aborted multipart uploads count=019302026/09/09 10:29:22 WARN Force mode enabled - objects will be deleted immediately without grace period19312026/09/09 10:29:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=790.552879ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1932--- PASS: TestUploadHandlersRejectOversizedBody (0.22s)1933 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.13s)1934 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.11s)1935 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.31s)19362026/09/09 10:29:23 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=01937=== NAME TestOrphanedObjectsGCStressTest1938 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19392026/09/09 10:29:23 INFO Vacuumed table table=pending_closures19402026/09/09 10:29:23 INFO Vacuumed table table=pending_objects19412026/09/09 10:29:23 INFO Vacuumed table table=multipart_uploads19422026/09/09 10:29:23 INFO Vacuumed table table=closures19432026/09/09 10:29:23 INFO Vacuumed table table=objects1944 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19452026/09/09 10:29:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.732043163s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19462026/09/09 10:29:23 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=019472026/09/09 10:29:23 INFO Vacuumed table table=pending_closures1948 orphaned_objects_gc_test.go:509: Stress test completed successfully:1949 orphaned_objects_gc_test.go:510: - Active objects preserved: 201950 orphaned_objects_gc_test.go:511: - Objects deleted: 2101951 orphaned_objects_gc_test.go:512: - Total GC'd: 2101952--- PASS: TestOrphanedObjectsGCStressTest (3.18s)19532026/09/09 10:29:23 INFO Vacuumed table table=pending_objects19542026/09/09 10:29:23 INFO Vacuumed table table=multipart_uploads19552026/09/09 10:29:23 INFO Vacuumed table table=closures19562026/09/09 10:29:23 INFO Vacuumed table table=objects19572026/09/09 10:29:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01958=== NAME TestClientIntegration1959 client_integration_test.go:304: Objects in database after GC:1960 client_integration_test.go:304: Successfully deleted all objects with GC --force1961--- PASS: TestClientIntegration (2.99s)19622026/09/09 10:29:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01963=== NAME TestPinProtectsFromGC1964 client_integration_test.go:711: Pin successfully protected closure from garbage collection1965--- PASS: TestPinProtectsFromGC (3.15s)19662026/09/09 10:29:25 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"19672026/09/09 10:29:25 WARN Rate limiter enabled after throttle name=s3-test rate=519682026/09/09 10:29:25 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1969=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1970 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101971 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001972--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.96s)19732026/09/09 10:29:25 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19742026/09/09 10:29:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.059896ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19752026/09/09 10:29:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.238586ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19762026/09/09 10:29:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.660969ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19772026/09/09 10:29:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.634417108s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1978--- PASS: TestClientErrorHandling (0.00s)1979 --- PASS: TestClientErrorHandling/InvalidStorePath (0.54s)1980 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.63s)1981 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.50s)1982PASS1983{"timestamp":"2026-09-09T10:29:28.453555297Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58446","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1866,"threadName":"rustfs-worker","threadId":"ThreadId(201)"}19842026-09-09 10:29:28.714 UTC [111] LOG: received smart shutdown request19852026-09-09 10:29:28.720 UTC [111] LOG: background worker "logical replication launcher" (PID 121) exited with exit code 119862026-09-09 10:29:28.733 UTC [116] LOG: shutting down19872026-09-09 10:29:28.734 UTC [116] LOG: checkpoint starting: shutdown immediate19882026-09-09 10:29:29.916 UTC [116] LOG: checkpoint complete: wrote 11401 buffers (69.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.258 s, sync=0.915 s, total=1.183 s; sync files=17141, longest=0.012 s, average=0.001 s; distance=236081 kB, estimate=236081 kB; lsn=0/FDF22D8, redo lsn=0/FDF22D819892026-09-09 10:29:29.977 UTC [111] LOG: database system is shut down1990Running OIDC tests...1991=== RUN TestGlobMatch1992=== PAUSE TestGlobMatch1993=== RUN TestAudienceForIssuer1994=== PAUSE TestAudienceForIssuer1995=== RUN TestValidateToken_ValidToken1996=== PAUSE TestValidateToken_ValidToken1997=== RUN TestValidateToken_WrongAudience1998=== PAUSE TestValidateToken_WrongAudience1999=== RUN TestValidateToken_Expired2000=== PAUSE TestValidateToken_Expired2001=== RUN TestValidateToken_BoundClaimsMismatch2002=== PAUSE TestValidateToken_BoundClaimsMismatch2003=== RUN TestValidateToken_BoundSubjectMismatch2004=== PAUSE TestValidateToken_BoundSubjectMismatch2005=== RUN TestValidateToken_MultipleProviders2006=== PAUSE TestValidateToken_MultipleProviders2007=== RUN TestValidateToken_NoMatchingProvider2008=== PAUSE TestValidateToken_NoMatchingProvider2009=== RUN TestValidateToken_KubernetesServiceAccount2010=== PAUSE TestValidateToken_KubernetesServiceAccount2011=== RUN TestNewValidator_KubernetesRequiresCA2012=== PAUSE TestNewValidator_KubernetesRequiresCA2013=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2014=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2015=== RUN TestScopes_LegacyProviderDefaultsToWrite2016=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2017=== RUN TestScopes_Rules2018=== PAUSE TestScopes_Rules2019=== RUN TestScopes_ConfigValidation2020=== PAUSE TestScopes_ConfigValidation2021=== CONT TestGlobMatch2022=== RUN TestGlobMatch/foo_foo2023=== CONT TestScopes_ConfigValidation2024=== CONT TestValidateToken_NoMatchingProvider2025=== CONT TestNewValidator_KubernetesRequiresCA2026=== PAUSE TestGlobMatch/foo_foo2027=== RUN TestGlobMatch/foo_bar2028=== PAUSE TestGlobMatch/foo_bar2029=== RUN TestGlobMatch/*_2030=== CONT TestValidateToken_MultipleProviders2031=== CONT TestValidateToken_BoundSubjectMismatch2032=== CONT TestValidateToken_BoundClaimsMismatch2033=== CONT TestValidateToken_Expired2034=== CONT TestValidateToken_WrongAudience2035=== CONT TestValidateToken_ValidToken2036=== CONT TestAudienceForIssuer2037--- PASS: TestAudienceForIssuer (0.00s)2038=== CONT TestScopes_LegacyProviderDefaultsToWrite2039=== CONT TestValidateToken_KubernetesServiceAccount2040=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2041=== CONT TestScopes_Rules2042=== PAUSE TestGlobMatch/*_2043=== RUN TestGlobMatch/*_anything2044=== PAUSE TestGlobMatch/*_anything2045=== RUN TestGlobMatch/foo*_foo2046=== PAUSE TestGlobMatch/foo*_foo2047=== RUN TestGlobMatch/foo*_foobar2048=== PAUSE TestGlobMatch/foo*_foobar2049=== RUN TestGlobMatch/foo*_bar2050=== PAUSE TestGlobMatch/foo*_bar2051=== RUN TestGlobMatch/*bar_bar2052=== PAUSE TestGlobMatch/*bar_bar2053=== RUN TestGlobMatch/*bar_foobar2054=== PAUSE TestGlobMatch/*bar_foobar2055=== RUN TestGlobMatch/*bar_foo2056=== PAUSE TestGlobMatch/*bar_foo2057=== RUN TestGlobMatch/foo*bar_foobar2058=== PAUSE TestGlobMatch/foo*bar_foobar2059=== RUN TestGlobMatch/foo*bar_foo123bar2060=== PAUSE TestGlobMatch/foo*bar_foo123bar2061=== RUN TestGlobMatch/foo*bar_foobarbaz2062--- PASS: TestScopes_ConfigValidation (0.01s)2063=== PAUSE TestGlobMatch/foo*bar_foobarbaz2064=== RUN TestGlobMatch/*/*_foo/bar2065=== PAUSE TestGlobMatch/*/*_foo/bar2066=== RUN TestGlobMatch/*/*_foo2067=== PAUSE TestGlobMatch/*/*_foo2068=== RUN TestGlobMatch/refs/heads/*_refs/heads/main20692026/09/09 10:29:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43307/oidc20702026/09/09 10:29:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38243/oidc20712026/09/09 10:29:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39757/oidc2072=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2073=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.020742026/09/09 10:29:30 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45557/oidc2075=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.020762026/09/09 10:29:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46171/oidc2077=== RUN TestGlobMatch/refs/*/main_refs/heads/main2078=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2079=== RUN TestGlobMatch/fo?_foo2080=== PAUSE TestGlobMatch/fo?_foo2081=== RUN TestGlobMatch/fo?_fo2082=== PAUSE TestGlobMatch/fo?_fo2083=== RUN TestGlobMatch/fo?_fooo20842026/09/09 10:29:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35883/oidc2085=== PAUSE TestGlobMatch/fo?_fooo2086=== RUN TestGlobMatch/?oo_foo2087=== PAUSE TestGlobMatch/?oo_foo20882026/09/09 10:29:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38901/oidc2089=== RUN TestGlobMatch/?oo_boo2090=== PAUSE TestGlobMatch/?oo_boo20912026/09/09 10:29:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34639/oidc2092=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2093=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2094=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2095=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2096=== CONT TestGlobMatch/foo_foo2097=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2098=== CONT TestGlobMatch/?oo_boo20992026/09/09 10:29:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39507/oidc2100=== CONT TestGlobMatch/foo*bar_foobarbaz21012026/09/09 10:29:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46357/oidc2102=== CONT TestGlobMatch/foo_bar2103=== CONT TestGlobMatch/refs/*/main_refs/heads/main2104=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2105=== CONT TestGlobMatch/fo?_fooo2106=== CONT TestGlobMatch/fo?_fo2107=== CONT TestGlobMatch/fo?_foo2108=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2109=== CONT TestGlobMatch/foo*bar_foo123bar2110=== CONT TestGlobMatch/*/*_foo2111=== CONT TestGlobMatch/*/*_foo/bar2112=== CONT TestGlobMatch/foo*bar_foobar2113=== CONT TestGlobMatch/*bar_foo2114=== CONT TestGlobMatch/*bar_foobar2115=== CONT TestGlobMatch/*bar_bar2116=== CONT TestGlobMatch/foo*_bar2117=== CONT TestGlobMatch/foo*_foobar2118=== CONT TestGlobMatch/foo*_foo2119=== CONT TestGlobMatch/*_anything2120=== CONT TestGlobMatch/*_2121=== CONT TestGlobMatch/?oo_foo2122=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02123--- PASS: TestGlobMatch (0.01s)2124 --- PASS: TestGlobMatch/foo_foo (0.00s)2125 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2126 --- PASS: TestGlobMatch/?oo_boo (0.00s)2127 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2128 --- PASS: TestGlobMatch/foo_bar (0.00s)2129 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2130 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2131 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2132 --- PASS: TestGlobMatch/fo?_fo (0.00s)2133 --- PASS: TestGlobMatch/fo?_foo (0.00s)2134 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2135 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2136 --- PASS: TestGlobMatch/*/*_foo (0.00s)2137 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2138 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2139 --- PASS: TestGlobMatch/*bar_foo (0.00s)2140 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2141 --- PASS: TestGlobMatch/*bar_bar (0.00s)2142 --- PASS: TestGlobMatch/foo*_bar (0.00s)2143 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2144 --- PASS: TestGlobMatch/foo*_foo (0.00s)2145 --- PASS: TestGlobMatch/*_anything (0.00s)2146 --- PASS: TestGlobMatch/*_ (0.00s)2147 --- PASS: TestGlobMatch/?oo_foo (0.00s)2148 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)21492026/09/09 10:29:30 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232150--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2151--- PASS: TestValidateToken_WrongAudience (0.01s)2152--- PASS: TestValidateToken_ValidToken (0.01s)2153--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2154--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2155--- PASS: TestValidateToken_MultipleProviders (0.02s)2156--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2157--- PASS: TestValidateToken_Expired (0.02s)21582026/09/09 10:29:30 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3990321592026/09/09 10:29:30 http: TLS handshake error from 127.0.0.1:53092: remote error: tls: bad certificate2160--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2161--- PASS: TestScopes_Rules (0.02s)2162--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2163--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2164PASS2165Running hook tests...2166=== RUN TestSendPathsEmpty2167=== PAUSE TestSendPathsEmpty2168=== RUN TestQueueEnqueueAndFetch2169=== PAUSE TestQueueEnqueueAndFetch2170=== RUN TestQueueDeduplication2171=== PAUSE TestQueueDeduplication2172=== RUN TestQueueRemove2173=== PAUSE TestQueueRemove2174=== RUN TestQueueFetchBatchLimit2175=== PAUSE TestQueueFetchBatchLimit2176=== RUN TestQueueRetryMovesToBack2177=== PAUSE TestQueueRetryMovesToBack2178=== RUN TestQueueFetchRemoveLifecycle2179=== PAUSE TestQueueFetchRemoveLifecycle2180=== RUN TestQueueConcurrentWriters2181=== PAUSE TestQueueConcurrentWriters2182=== RUN TestQueueRemoveLargeClosure2183=== PAUSE TestQueueRemoveLargeClosure2184=== RUN TestServerClientIntegration2185=== PAUSE TestServerClientIntegration2186=== RUN TestServerQueueError2187=== PAUSE TestServerQueueError2188=== RUN TestGetListenerSocketActivation2189 server_test.go:210: === RUN TestGetListenerSocketActivation2190 --- PASS: TestGetListenerSocketActivation (0.00s)2191 PASS2192 2193--- PASS: TestGetListenerSocketActivation (0.01s)2194=== RUN TestDrainIsolatesPoisonPath2195=== PAUSE TestDrainIsolatesPoisonPath2196=== RUN TestRunNotBlockedByPoisonHead2197=== PAUSE TestRunNotBlockedByPoisonHead2198=== RUN TestDrainGivesUpWhenServerDown2199=== PAUSE TestDrainGivesUpWhenServerDown2200=== RUN TestFailedPathPrunedByLaterClosure2201=== PAUSE TestFailedPathPrunedByLaterClosure2202=== RUN TestWorkerUploadsAndRemoves2203=== PAUSE TestWorkerUploadsAndRemoves2204=== RUN TestWorkerSkipsGCdPaths2205=== PAUSE TestWorkerSkipsGCdPaths2206=== RUN TestWorkerPrunesClosureDeps2207=== PAUSE TestWorkerPrunesClosureDeps2208=== RUN TestDrainTimeout2209=== PAUSE TestDrainTimeout2210=== CONT TestSendPathsEmpty2211=== CONT TestQueueRetryMovesToBack2212=== CONT TestQueueRemoveLargeClosure2213--- PASS: TestSendPathsEmpty (0.00s)2214=== CONT TestQueueFetchBatchLimit2215=== CONT TestServerQueueError2216=== CONT TestQueueRemove2217=== CONT TestQueueDeduplication2218=== CONT TestDrainTimeout2219=== CONT TestQueueEnqueueAndFetch2220=== CONT TestWorkerPrunesClosureDeps2221=== CONT TestServerClientIntegration2222=== CONT TestWorkerSkipsGCdPaths2223=== CONT TestWorkerUploadsAndRemoves2224=== CONT TestQueueConcurrentWriters22252026/09/09 10:29:31 ERROR Failed to queue paths error="permission denied" count=12226=== CONT TestFailedPathPrunedByLaterClosure2227=== CONT TestQueueFetchRemoveLifecycle2228--- PASS: TestServerQueueError (0.00s)2229=== CONT TestDrainGivesUpWhenServerDown2230=== CONT TestRunNotBlockedByPoisonHead2231=== CONT TestDrainIsolatesPoisonPath2232--- PASS: TestServerClientIntegration (0.00s)22332026/09/09 10:29:31 INFO Upload queue status pending=222342026/09/09 10:29:31 INFO Upload queue status pending=222352026/09/09 10:29:31 INFO Uploading batch count=122362026/09/09 10:29:31 INFO Uploading batch count=222372026/09/09 10:29:31 INFO Upload queue status pending=222382026/09/09 10:29:31 INFO Uploading batch count=222392026/09/09 10:29:31 INFO Uploading batch count=422402026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=422412026/09/09 10:29:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2318656514/002/nonexistent22422026/09/09 10:29:31 INFO Uploading batch count=122432026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=122442026/09/09 10:29:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath649967661/002/bbb2245--- PASS: TestQueueEnqueueAndFetch (0.01s)22462026/09/09 10:29:31 INFO Uploading batch count=12247--- PASS: TestQueueRemove (0.01s)2248--- PASS: TestQueueDeduplication (0.01s)22492026/09/09 10:29:31 INFO Uploading batch count=222502026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=222512026/09/09 10:29:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2626759751/002/a2252--- PASS: TestQueueRetryMovesToBack (0.02s)22532026/09/09 10:29:31 INFO Upload queue status pending=322542026/09/09 10:29:31 INFO Uploading batch count=122552026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=122562026/09/09 10:29:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2626759751/002/b22572026/09/09 10:29:31 INFO Uploading batch count=122582026/09/09 10:29:31 INFO Uploading batch count=222592026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=222602026/09/09 10:29:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2626759751/002/c22612026/09/09 10:29:31 INFO Uploading batch count=12262--- PASS: TestQueueFetchBatchLimit (0.02s)22632026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=12264--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22652026/09/09 10:29:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2626759751/002/d22662026/09/09 10:29:31 INFO Uploading batch count=122672026/09/09 10:29:31 INFO Uploading batch count=122682026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=122692026/09/09 10:29:31 INFO Uploading batch count=222702026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=222712026/09/09 10:29:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2626759751/002/e22722026/09/09 10:29:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2626759751/002/f22732026/09/09 10:29:31 INFO Uploading batch count=122742026/09/09 10:29:31 ERROR Upload failed error="upload failed" count=122752026/09/09 10:29:31 ERROR Drain finished with paths left in queue remaining=1022762026/09/09 10:29:31 ERROR Drain finished with paths left in queue remaining=12277--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2278--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2279--- PASS: TestDrainIsolatesPoisonPath (0.02s)2280--- PASS: TestWorkerPrunesClosureDeps (0.03s)2281--- PASS: TestWorkerUploadsAndRemoves (0.03s)2282--- PASS: TestWorkerSkipsGCdPaths (0.03s)22832026/09/09 10:29:31 ERROR Upload failed error="context deadline exceeded" count=222842026/09/09 10:29:31 ERROR Drain finished with paths left in queue remaining=42285--- PASS: TestDrainTimeout (0.22s)2286--- PASS: TestQueueRemoveLargeClosure (0.23s)2287--- PASS: TestQueueConcurrentWriters (0.25s)22882026/09/09 10:29:32 INFO Uploading batch count=122892026/09/09 10:29:32 INFO Uploading batch count=122902026/09/09 10:29:32 INFO Uploading batch count=122912026/09/09 10:29:32 ERROR Upload failed error="upload failed" count=122922026/09/09 10:29:32 INFO Uploading batch count=122932026/09/09 10:29:32 ERROR Upload failed error="upload failed" count=122942026/09/09 10:29:32 INFO Uploading batch count=122952026/09/09 10:29:32 ERROR Upload failed error="upload failed" count=122962026/09/09 10:29:32 INFO Uploading batch count=122972026/09/09 10:29:32 ERROR Upload failed error="upload failed" count=122982026/09/09 10:29:32 ERROR Drain finished with paths left in queue remaining=12299--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2300PASS