niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #237
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestSetClientTLS66=== PAUSE TestSetClientTLS67=== RUN TestSetClientTLSDoesNotMutateDefaultTransport68=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport69=== RUN TestSetClientTLSErrors70=== PAUSE TestSetClientTLSErrors71=== RUN TestStaticToken72=== PAUSE TestStaticToken73=== RUN TestFileTokenReadsAndCaches74=== PAUSE TestFileTokenReadsAndCaches75=== RUN TestFileTokenMissing76=== PAUSE TestFileTokenMissing77=== RUN TestFileTokenEmpty78=== PAUSE TestFileTokenEmpty79=== RUN TestScriptTokenNoExpiryRerunsEveryCall80=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall81=== RUN TestScriptTokenCachesUntilRefresh82=== PAUSE TestScriptTokenCachesUntilRefresh83=== RUN TestScriptTokenEmptyToken84=== PAUSE TestScriptTokenEmptyToken85=== RUN TestScriptTokenBadJSON86=== PAUSE TestScriptTokenBadJSON87=== RUN TestScriptTokenScriptFails88=== PAUSE TestScriptTokenScriptFails89=== RUN TestScriptTokenEmptyCommand90=== PAUSE TestScriptTokenEmptyCommand91=== CONT TestDoServerRequestAttachesToken92=== CONT TestFileTokenMissing93=== CONT TestPathInfoCACompatibility94=== CONT TestFileTokenReadsAndCaches95=== CONT TestStaticToken96=== CONT TestSetClientTLSErrors97--- PASS: TestStaticToken (0.00s)98=== CONT TestDumpPathWriterError99--- PASS: TestFileTokenMissing (0.00s)100=== CONT TestScriptTokenCachesUntilRefresh101=== CONT TestSetClientTLSDoesNotMutateDefaultTransport102=== CONT TestSetClientTLS103=== CONT TestStreamPushRequestLine104=== CONT TestStreamPushGivesUpOnDeadServer105--- PASS: TestFileTokenReadsAndCaches (0.00s)106=== CONT TestStreamPushBatchesUnderLoad107=== CONT TestScriptTokenScriptFails108=== CONT TestStreamPushReportsEveryPath109=== CONT TestShellSplitErrors110=== CONT TestShellSplit111=== CONT TestScriptTokenEmptyCommand112=== CONT TestScriptTokenEmptyToken113=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess114=== CONT TestResolveStorePath115=== CONT TestDoWithRetry_BodyReplayedViaGetBody116=== CONT TestRateLimiterFeedback117=== CONT TestScriptTokenBadJSON118=== CONT TestScriptTokenNoExpiryRerunsEveryCall119=== RUN TestPathInfoCACompatibility/null_ca_field120=== CONT TestStreamPushIsolatesFailures121=== CONT TestParsePathInfoJSONMultiplePaths1222026/09/21 14:12:11 WARN Rate limiter enabled after throttle name=server-test rate=5123--- PASS: TestShellSplitErrors (0.00s)1242026/09/21 14:12:11 ERROR Upload failed error="connection refused" count=20125=== CONT TestFileTokenEmpty1262026/09/21 14:12:11 ERROR Server seems unavailable, giving up on batch untried=17127--- PASS: TestScriptTokenEmptyCommand (0.00s)128=== CONT TestConvertHashToNix32129=== RUN TestConvertHashToNix32/SRI_format_to_Nix32130--- PASS: TestShellSplit (0.00s)131=== CONT TestGetStorePathHash132=== RUN TestGetStorePathHash/valid_store_path133=== PAUSE TestGetStorePathHash/valid_store_path134=== RUN TestGetStorePathHash/basename_without_hyphen_should_error135=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error136=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error137=== RUN TestRateLimiterFeedback/429_enables_limiter138--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)139--- PASS: TestStreamPushReportsEveryPath (0.00s)140=== CONT TestParsePathInfoJSON141=== CONT TestEncodeNixBase32WithRealHash142--- PASS: TestEncodeNixBase32WithRealHash (0.00s)143=== CONT TestEncodeNixBase32144--- PASS: TestScriptTokenScriptFails (0.01s)145--- PASS: TestResolveStorePath (0.00s)146=== CONT TestDumpPathSingleFile147--- PASS: TestFileTokenEmpty (0.00s)148=== CONT TestFilterOversizedClosures149=== RUN TestSetClientTLSErrors/missing_cert_file150=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths154=== CONT TestDumpPathMatchesNix155=== PAUSE TestRateLimiterFeedback/429_enables_limiter156=== PAUSE TestPathInfoCACompatibility/null_ca_field157=== RUN TestParsePathInfoJSON/Nix_format1582026/09/21 14:12:11 ERROR Upload failed error=boom count=11592026/09/21 14:12:11 ERROR Upload failed error="bad path" count=3160=== RUN TestEncodeNixBase32/test_string_hash161=== PAUSE TestEncodeNixBase32/test_string_hash162=== RUN TestFilterOversizedClosures/no_limit_keeps_everything163=== PAUSE TestSetClientTLSErrors/missing_cert_file164=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32165=== CONT TestPathInfoHashCompatibility166=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error167=== RUN TestRateLimiterFeedback/503_enables_limiter168=== RUN TestPathInfoCACompatibility/old_string_format_-_text169=== PAUSE TestParsePathInfoJSON/Nix_format170--- PASS: TestStreamPushIsolatesFailures (0.01s)171=== CONT TestUploadMultipart_SupersededByPeer172=== CONT TestUploadMultipart_PartsInParallel173=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything174--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)175=== PAUSE TestRateLimiterFeedback/503_enables_limiter176=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)177=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter178=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped179=== RUN TestConvertHashToNix32/already_Nix32_format180=== RUN TestSetClientTLSErrors/missing_key_file181=== RUN TestEncodeNixBase32/empty_input182=== RUN TestParsePathInfoJSON/Lix_format183--- PASS: TestScriptTokenBadJSON (0.01s)184--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)185--- PASS: TestScriptTokenEmptyToken (0.01s)186=== PAUSE TestParsePathInfoJSON/Lix_format187=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error188=== RUN TestUploadMultipart_SupersededByPeer/exists189=== CONT TestPartSizeForNAR1902026/09/21 14:12:11 WARN Rate limiter enabled after throttle name=server-test rate=5191=== PAUSE TestUploadMultipart_SupersededByPeer/exists192=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text193=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1942026/09/21 14:12:11 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41735195=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon197=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI198=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI199=== RUN TestParsePathInfoJSON/empty_input200=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths201=== PAUSE TestParsePathInfoJSON/empty_input202=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error203=== CONT TestRegisterUploadedObjectReusesConnections204=== RUN TestSetClientTLS/rejects_connection_without_client_cert2052026/09/21 14:12:11 WARN Rate limiter backed off name=server-test rate=5206=== RUN TestPartSizeForNAR/zero_stays_at_minimum207=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter2082026/09/21 14:12:11 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41735209=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== RUN TestFilterOversizedClosures/all_closures_skipped211=== PAUSE TestFilterOversizedClosures/all_closures_skipped212=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error213=== RUN TestUploadMultipart_SupersededByPeer/missing214=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive215=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512216--- PASS: TestDoServerRequestAttachesToken (0.01s)217=== CONT TestCaseHackSuffix218=== PAUSE TestEncodeNixBase32/empty_input219=== PAUSE TestSetClientTLSErrors/missing_key_file220=== PAUSE TestConvertHashToNix32/already_Nix32_format221=== RUN TestParsePathInfoJSON/whitespace_only222=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths223=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter224=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert225=== CONT TestGetStorePathHash/valid_store_path226=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum227=== RUN TestSetClientTLSErrors/missing_ca_file228=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error229=== CONT TestFilterOversizedClosures/no_limit_keeps_everything230=== PAUSE TestUploadMultipart_SupersededByPeer/missing231=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512232=== CONT TestEncodeNixBase32/test_string_hash233=== RUN TestConvertHashToNix32/invalid_format234=== CONT TestFilterOversizedClosures/all_closures_skipped235=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter2362026/09/21 14:12:11 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=50237=== CONT TestUploadMultipart_SupersededByPeer/missing238=== PAUSE TestParsePathInfoJSON/whitespace_only239--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)240 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)241 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)242=== CONT TestEncodeNixBase32/empty_input243--- PASS: TestEncodeNixBase32 (0.01s)244 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)245 --- PASS: TestEncodeNixBase32/empty_input (0.00s)246=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive247=== RUN TestPathInfoCACompatibility/new_structured_format_-_text248=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text249=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method250=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method251=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)252=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512253=== CONT TestUploadMultipart_SupersededByPeer/exists254=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter255=== CONT TestRateLimiterFeedback/503_enables_limiter256=== RUN TestParsePathInfoJSON/invalid_JSON257=== CONT TestRateLimiterFeedback/429_enables_limiter258=== PAUSE TestParsePathInfoJSON/invalid_JSON259--- PASS: TestDumpPathSingleFile (0.05s)260=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter261--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.06s)262--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)263=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA264=== CONT TestGetStorePathHash/basename_without_hyphen_should_error265=== CONT TestPathInfoCACompatibility/null_ca_field266=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI267=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon268=== PAUSE TestConvertHashToNix32/invalid_format269=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped270=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method271=== CONT TestPathInfoCACompatibility/old_string_format_-_text272=== CONT TestParsePathInfoJSON/Nix_format273=== RUN TestPartSizeForNAR/small_stays_at_minimum274=== PAUSE TestPartSizeForNAR/small_stays_at_minimum275=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum276=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum277=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts278=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts279=== RUN TestPartSizeForNAR/1_TiB280=== CONT TestPathInfoCACompatibility/new_structured_format_-_text281=== CONT TestParsePathInfoJSON/whitespace_only282=== CONT TestConvertHashToNix32/SRI_format_to_Nix32283=== CONT TestConvertHashToNix32/invalid_format2842026/09/21 14:12:11 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=2000285=== CONT TestConvertHashToNix32/already_Nix32_format286=== PAUSE TestPartSizeForNAR/1_TiB287=== RUN TestPartSizeForNAR/5_TiB_S3_max_object288=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object289=== RUN TestPartSizeForNAR/capped_at_5_GiB290=== PAUSE TestPartSizeForNAR/capped_at_5_GiB291=== CONT TestPartSizeForNAR/zero_stays_at_minimum2922026/09/21 14:12:11 WARN Rate limiter enabled after throttle name=server-test rate=5293=== PAUSE TestSetClientTLSErrors/missing_ca_file294=== RUN TestSetClientTLSErrors/invalid_ca_file2952026/09/21 14:12:11 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35175296=== PAUSE TestSetClientTLSErrors/invalid_ca_file297=== CONT TestSetClientTLSErrors/missing_cert_file298=== CONT TestPartSizeForNAR/capped_at_5_GiB299=== CONT TestPartSizeForNAR/5_TiB_S3_max_object300=== CONT TestPartSizeForNAR/1_TiB301=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts302=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum303=== CONT TestPartSizeForNAR/small_stays_at_minimum304=== CONT TestSetClientTLSErrors/invalid_ca_file3052026/09/21 14:12:11 WARN Rate limiter enabled after throttle name=server-test rate=53062026/09/21 14:12:11 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:404053072026/09/21 14:12:11 WARN Rate limiter backed off name=server-test rate=5308=== CONT TestParsePathInfoJSON/invalid_JSON309=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA310=== CONT TestSetClientTLSErrors/missing_key_file311=== CONT TestParsePathInfoJSON/Lix_format312--- PASS: TestPathInfoHashCompatibility (0.05s)313 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)314 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)315 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)316 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)317--- PASS: TestGetStorePathHash (0.01s)318 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)319 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)320 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)321 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3222026/09/21 14:12:11 WARN Rate limiter backed off name=server-test rate=5323=== CONT TestSetClientTLSErrors/missing_ca_file324=== CONT TestParsePathInfoJSON/empty_input325=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive326=== RUN TestSetClientTLS/preserves_debug_logging_transport327=== PAUSE TestSetClientTLS/preserves_debug_logging_transport328--- PASS: TestFilterOversizedClosures (0.01s)329 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)330 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)331 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)332=== CONT TestSetClientTLS/rejects_connection_without_client_cert333=== CONT TestSetClientTLS/preserves_debug_logging_transport334=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA335--- PASS: TestConvertHashToNix32 (0.06s)336 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)337 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)338 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)339--- PASS: TestUploadMultipart_SupersededByPeer (0.05s)340 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)341 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)342--- PASS: TestRateLimiterFeedback (0.05s)343 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)344 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)345 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)346 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)347--- PASS: TestPartSizeForNAR (0.06s)348 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)349 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)350 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)351 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)352 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)353 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)354 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)355--- PASS: TestParsePathInfoJSON (0.06s)356 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)357 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)358 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)359 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)360 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)361--- PASS: TestPathInfoCACompatibility (0.06s)362 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)363 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)364 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)365 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)366 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)367--- PASS: TestSetClientTLSErrors (0.07s)368 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)369 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)370 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)371 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3722026/09/21 14:12:11 http: TLS handshake error from 127.0.0.1:39408: remote error: tls: bad certificate373--- PASS: TestSetClientTLS (0.07s)374 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)375 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)376 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)377--- PASS: TestStreamPushRequestLine (0.09s)378--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)379--- PASS: TestCaseHackSuffix (0.03s)380--- PASS: TestDumpPathWriterError (0.10s)381--- PASS: TestStreamPushBatchesUnderLoad (0.11s)382--- PASS: TestDumpPathMatchesNix (0.13s)383--- PASS: TestUploadMultipart_PartsInParallel (0.66s)384--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)385PASS386Running server tests...387The files belonging to this database system will be owned by user "nixbld".388This user must also own the server process.389390The database cluster will be initialized with locale "C".391The default database encoding has accordingly been set to "SQL_ASCII".392The default text search configuration will be set to "english".393394Data page checksums are enabled.395396creating directory /build/postgres2307735054/data ... ok397creating subdirectories ... ok398selecting dynamic shared memory implementation ... posix399selecting default "max_connections" ... 100400selecting default "shared_buffers" ... 128MB401selecting default time zone ... UTC402creating configuration files ... ok403running bootstrap script ... ok404performing post-bootstrap initialization ... ok405syncing data to disk ... ok406407initdb: warning: enabling "trust" authentication for local connections408initdb: 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.409410Success. You can now start the database server using:411412 pg_ctl -D /build/postgres2307735054/data -l logfile start413414/build/postgres2307735054:5432 - no response4152026-09-21 14:12:13.374 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4162026-09-21 14:12:13.375 UTC [129] LOG: listening on Unix socket "/build/postgres2307735054/.s.PGSQL.5432"4172026-09-21 14:12:13.380 UTC [136] LOG: database system was shut down at 2026-09-21 14:12:13 UTC4182026-09-21 14:12:13.384 UTC [129] LOG: database system is ready to accept connections419/build/postgres2307735054:5432 - accepting connections420{"timestamp":"2026-09-21T14:12:13.684844242Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6141f884-08f2-4d2d-91ab-c580017f57f1","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":430,"threadName":"rustfs-worker","threadId":"ThreadId(399)"}421=== RUN TestService_AuthMiddleware422=== PAUSE TestService_AuthMiddleware423=== RUN TestService_AuthMiddleware_MTLSProxyHeader424=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader425=== RUN TestService_AuthMiddleware_MTLSBoundSubjects426=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects427=== RUN TestService_ReadAuthMiddleware428=== PAUSE TestService_ReadAuthMiddleware429=== RUN TestService_AuthMiddleware_OIDC430=== PAUSE TestService_AuthMiddleware_OIDC431=== RUN TestService_RequireScope_OIDC432=== PAUSE TestService_RequireScope_OIDC433=== RUN TestService_ReadScope_PublicByDefault434=== PAUSE TestService_ReadScope_PublicByDefault435=== RUN TestCacheConfigHandler436=== PAUSE TestCacheConfigHandler437=== RUN TestCacheStatsHandler438=== PAUSE TestCacheStatsHandler439=== RUN TestClientCADerivations440=== PAUSE TestClientCADerivations441=== RUN TestClientErrorHandling442=== PAUSE TestClientErrorHandling443=== RUN TestClientIntegration444=== PAUSE TestClientIntegration445=== RUN TestClientMultipleUploads446=== PAUSE TestClientMultipleUploads447=== RUN TestClientWithDependencies448=== PAUSE TestClientWithDependencies449=== RUN TestClientSharedPathCommittedMidPush450=== PAUSE TestClientSharedPathCommittedMidPush451=== RUN TestPinProtectsFromGC452=== PAUSE TestPinProtectsFromGC453=== RUN TestResolveDBConnectionString454=== PAUSE TestResolveDBConnectionString455=== RUN TestLeadElectsOneAndHandsOver456=== PAUSE TestLeadElectsOneAndHandsOver457=== RUN TestLeadIncumbentWinsAfterRestart4582026-09-21 14:12:13.882 UTC [569] ERROR: relation "goose_db_version" does not exist at character 364592026-09-21 14:12:13.882 UTC [569] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4602026/09/21 14:12:13 OK 20241026095416_initial_model.sql (6.76ms)4612026/09/21 14:12:13 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)4622026/09/21 14:12:13 OK 20251218171726_add_pins.sql (1.99ms)4632026/09/21 14:12:13 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)4642026/09/21 14:12:13 OK 20260905000000_add_claims.sql (2.4ms)4652026/09/21 14:12:13 OK 20260920000000_drop_claims.sql (1.48ms)4662026/09/21 14:12:13 goose: successfully migrated database to version: 202609200000004672026/09/21 14:12:13 OK 1_commit_pending_closure.sql (1.41ms)4682026/09/21 14:12:13 OK 2_object_stats_trigger.sql (799.5µs)4692026/09/21 14:12:13 goose: up to current file version: 24702026/09/21 14:12:13 INFO lead: acquired remote=192.0.2.1:12344712026/09/21 14:12:14 INFO lead: released remote=192.0.2.1:12344722026/09/21 14:12:14 INFO lead: acquired remote=192.0.2.1:12344732026/09/21 14:12:14 INFO lead: released remote=192.0.2.1:1234474--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)475=== RUN TestLeadEndsOnShutdown476=== PAUSE TestLeadEndsOnShutdown477=== RUN TestGCAdvisoryLockBlocksConcurrentRun4782026-09-21 14:12:14.650 UTC [578] ERROR: relation "goose_db_version" does not exist at character 364792026-09-21 14:12:14.650 UTC [578] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4802026/09/21 14:12:14 OK 20241026095416_initial_model.sql (6.45ms)4812026/09/21 14:12:14 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)4822026/09/21 14:12:14 OK 20251218171726_add_pins.sql (2.4ms)4832026/09/21 14:12:14 OK 20260628120000_add_object_size_and_stats.sql (1.91ms)4842026/09/21 14:12:14 OK 20260905000000_add_claims.sql (2.18ms)4852026/09/21 14:12:14 OK 20260920000000_drop_claims.sql (1.48ms)4862026/09/21 14:12:14 goose: successfully migrated database to version: 202609200000004872026/09/21 14:12:14 OK 1_commit_pending_closure.sql (1.63ms)4882026/09/21 14:12:14 OK 2_object_stats_trigger.sql (838.77µs)4892026/09/21 14:12:14 goose: up to current file version: 2490--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)491=== RUN TestGCBugBareHashReferences492=== PAUSE TestGCBugBareHashReferences493=== RUN TestGCMetrics494=== PAUSE TestGCMetrics495=== RUN TestGCTaskStore_StartNew496=== PAUSE TestGCTaskStore_StartNew497=== RUN TestGCTaskStore_DeduplicateSameParams498=== PAUSE TestGCTaskStore_DeduplicateSameParams499=== RUN TestGCTaskStore_ConflictDifferentParams500=== PAUSE TestGCTaskStore_ConflictDifferentParams501=== RUN TestGCTaskStore_GetEmpty502=== PAUSE TestGCTaskStore_GetEmpty503=== RUN TestGCTaskStore_GetReturnsLatest504=== PAUSE TestGCTaskStore_GetReturnsLatest505=== RUN TestGCTaskStore_CompletedAllowsNewTask506=== PAUSE TestGCTaskStore_CompletedAllowsNewTask507=== RUN TestGCTaskStore_PhaseUpdates508=== PAUSE TestGCTaskStore_PhaseUpdates509=== RUN TestGCTaskStore_Fail510=== PAUSE TestGCTaskStore_Fail511=== RUN TestGracefulShutdownDrainsInflight512=== PAUSE TestGracefulShutdownDrainsInflight513=== RUN TestService_healthCheckHandler514=== PAUSE TestService_healthCheckHandler515=== RUN TestService_readinessHandler516=== PAUSE TestService_readinessHandler517=== RUN TestGenerateLandingPage518=== PAUSE TestGenerateLandingPage519=== RUN TestCacheConfigHandlerMaxNarSize520=== PAUSE TestCacheConfigHandlerMaxNarSize521=== RUN TestCreatePendingClosureRejectsOversizedNAR522=== PAUSE TestCreatePendingClosureRejectsOversizedNAR523=== RUN TestNARDeduplicationMetadataUploadBug524=== PAUSE TestNARDeduplicationMetadataUploadBug525=== RUN TestMetricsInventory526=== PAUSE TestMetricsInventory527=== RUN TestService_NativeMTLS528=== PAUSE TestService_NativeMTLS529=== RUN TestServerTLSConfig530=== PAUSE TestServerTLSConfig531=== RUN TestMultipartCleanup532=== PAUSE TestMultipartCleanup533=== RUN TestObjectStatsTrigger534=== PAUSE TestObjectStatsTrigger535=== RUN TestOrphanedObjectsGC536=== PAUSE TestOrphanedObjectsGC537=== RUN TestOrphanedObjectsGCStressTest538=== PAUSE TestOrphanedObjectsGCStressTest539=== RUN TestResurrectedObjectNotDeleted540=== PAUSE TestResurrectedObjectNotDeleted541=== RUN TestParseSingleRange542=== PAUSE TestParseSingleRange543=== RUN TestIsValidCachePath544=== PAUSE TestIsValidCachePath545=== RUN TestReadProxyNarinfo546=== PAUSE TestReadProxyNarinfo547=== RUN TestReadProxyNarinfoAlreadyDecompressed548=== PAUSE TestReadProxyNarinfoAlreadyDecompressed549=== RUN TestReadProxyNarStreaming550=== PAUSE TestReadProxyNarStreaming551=== RUN TestReadProxy404552=== PAUSE TestReadProxy404553=== RUN TestReadProxyInvalidPath554=== PAUSE TestReadProxyInvalidPath555=== RUN TestReadProxyHead556=== PAUSE TestReadProxyHead557=== RUN TestReadProxyConditionalGet558=== PAUSE TestReadProxyConditionalGet559=== RUN TestReadProxyRootRedirectsToIndexHTML560=== PAUSE TestReadProxyRootRedirectsToIndexHTML561=== RUN TestReadProxyDisabled562=== PAUSE TestReadProxyDisabled563=== RUN TestReadRedirectNar564=== PAUSE TestReadRedirectNar565=== RUN TestReadRedirectKeepsNarinfoProxied566=== PAUSE TestReadRedirectKeepsNarinfoProxied567=== RUN TestReadProxyRangeRequest568=== PAUSE TestReadProxyRangeRequest569=== RUN TestReadRedirectUsesPublicS3URL570=== PAUSE TestReadRedirectUsesPublicS3URL571=== RUN TestRedundantMultipartUpload572=== PAUSE TestRedundantMultipartUpload573=== RUN TestCompleteMultipartUpload_ErrorButObjectExists574=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists575=== RUN TestCompletedNarNotReofferedAcrossClosures576=== PAUSE TestCompletedNarNotReofferedAcrossClosures577=== RUN TestPresignedUploadRegisteredBeforeCommit578=== PAUSE TestPresignedUploadRegisteredBeforeCommit579=== RUN TestService_Rustfstest580=== PAUSE TestService_Rustfstest581=== RUN TestParseSize582=== PAUSE TestParseSize583=== RUN TestSkippedUploadsHandler584=== PAUSE TestSkippedUploadsHandler585=== RUN TestSystemdListenerNotActivated586--- PASS: TestSystemdListenerNotActivated (0.00s)587=== RUN TestWatchdogBeatsWhenHealthy588--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)589=== RUN TestWatchdogSkipsWhenUnhealthy5902026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5912026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5972026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5982026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5992026/09/21 14:12:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"600--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)601=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle602=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle603=== RUN TestProxyWriteTimeout604=== PAUSE TestProxyWriteTimeout605=== RUN TestIsValidUploadKey606=== PAUSE TestIsValidUploadKey607=== RUN TestUploadHandlersRejectInvalidKeys608=== PAUSE TestUploadHandlersRejectInvalidKeys609=== RUN TestUploadHandlersRejectOversizedBody610=== PAUSE TestUploadHandlersRejectOversizedBody611=== RUN TestService_cleanupPendingClosuresHandler612=== PAUSE TestService_cleanupPendingClosuresHandler613=== RUN TestService_createPendingClosureHandler614=== PAUSE TestService_createPendingClosureHandler615=== RUN TestService_verifyS3Integrity616=== PAUSE TestService_verifyS3Integrity617=== RUN TestCompleteMultipartUnregistered618=== PAUSE TestCompleteMultipartUnregistered619=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT620=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT621=== CONT TestService_AuthMiddleware622=== CONT TestService_Rustfstest623=== CONT TestReadProxyInvalidPath624=== CONT TestGCBugBareHashReferences625=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT626=== CONT TestService_NativeMTLS627=== CONT TestService_verifyS3Integrity628=== CONT TestService_createPendingClosureHandler629=== CONT TestService_cleanupPendingClosuresHandler630=== CONT TestUploadHandlersRejectOversizedBody631=== CONT TestUploadHandlersRejectInvalidKeys632=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info633=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info634=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal635=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal636=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key637=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key638=== CONT TestIsValidUploadKey639=== CONT TestProxyWriteTimeout640=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle641=== CONT TestSkippedUploadsHandler642=== CONT TestParseSize643=== CONT TestMetricsInventory644=== CONT TestNARDeduplicationMetadataUploadBug645=== CONT TestCreatePendingClosureRejectsOversizedNAR646=== CONT TestCacheConfigHandlerMaxNarSize647=== CONT TestGenerateLandingPage648=== CONT TestService_readinessHandler649=== CONT TestService_healthCheckHandler650=== CONT TestCompleteMultipartUnregistered651=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key652=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key653=== CONT TestGracefulShutdownDrainsInflight6542026/09/21 14:12:14 INFO Client skipped oversized paths paths=3 nar_bytes=50000000006552026/09/21 14:12:14 INFO Starting HTTP server address=127.0.0.1:431956562026/09/21 14:12:14 INFO Received uploads request method=POST path=/api/pending_closures657--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)658=== CONT TestGCTaskStore_Fail659--- PASS: TestGCTaskStore_Fail (0.00s)660=== CONT TestGCTaskStore_PhaseUpdates661--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)662=== CONT TestGCTaskStore_CompletedAllowsNewTask663--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)664=== CONT TestGCTaskStore_GetReturnsLatest665--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)666=== CONT TestGCTaskStore_GetEmpty667--- PASS: TestGCTaskStore_GetEmpty (0.00s)668=== RUN TestProxyWriteTimeout/narinfo669=== PAUSE TestProxyWriteTimeout/narinfo670=== RUN TestIsValidUploadKey/narinfo671=== CONT TestGCTaskStore_DeduplicateSameParams672=== CONT TestGCMetrics6732026/09/21 14:12:15 INFO Shutdown signal received, draining in-flight requests timeout=10s674=== CONT TestGCTaskStore_ConflictDifferentParams675=== CONT TestReadProxyRangeRequest676=== RUN TestProxyWriteTimeout/1_GiB_nar677--- PASS: TestParseSize (0.00s)678--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)679--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)680--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)681=== CONT TestGCTaskStore_StartNew682=== PAUSE TestIsValidUploadKey/narinfo683=== PAUSE TestProxyWriteTimeout/1_GiB_nar684--- PASS: TestGCTaskStore_StartNew (0.00s)685=== RUN TestIsValidUploadKey/nar_zst686=== CONT TestPresignedUploadRegisteredBeforeCommit687=== RUN TestProxyWriteTimeout/10_GiB_nar688=== PAUSE TestProxyWriteTimeout/10_GiB_nar689=== PAUSE TestIsValidUploadKey/nar_zst690=== RUN TestProxyWriteTimeout/unknown_size691=== PAUSE TestProxyWriteTimeout/unknown_size692=== RUN TestIsValidUploadKey/nar_xz693=== PAUSE TestIsValidUploadKey/nar_xz694=== CONT TestCompletedNarNotReofferedAcrossClosures695=== RUN TestIsValidUploadKey/nar_plain696=== PAUSE TestIsValidUploadKey/nar_plain697=== RUN TestIsValidUploadKey/listing698=== PAUSE TestIsValidUploadKey/listing699=== RUN TestIsValidUploadKey/build_log700=== PAUSE TestIsValidUploadKey/build_log701=== RUN TestIsValidUploadKey/build_log_home-manager_file702=== PAUSE TestIsValidUploadKey/build_log_home-manager_file703=== RUN TestIsValidUploadKey/build_log_plus_in_name704=== PAUSE TestIsValidUploadKey/build_log_plus_in_name705=== RUN TestIsValidUploadKey/build_log_question_mark706=== PAUSE TestIsValidUploadKey/build_log_question_mark707=== RUN TestIsValidUploadKey/build_log_equals708=== PAUSE TestIsValidUploadKey/build_log_equals709=== RUN TestIsValidUploadKey/realisation710=== PAUSE TestIsValidUploadKey/realisation711=== RUN TestIsValidUploadKey/realisation_plus_in_output712=== PAUSE TestIsValidUploadKey/realisation_plus_in_output713=== RUN TestIsValidUploadKey/nix-cache-info714=== PAUSE TestIsValidUploadKey/nix-cache-info715=== RUN TestIsValidUploadKey/index.html716=== PAUSE TestIsValidUploadKey/index.html717--- PASS: TestGenerateLandingPage (0.01s)718=== RUN TestIsValidUploadKey/narinfo_key,_nar_type719=== CONT TestCompleteMultipartUpload_ErrorButObjectExists720=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type721=== RUN TestIsValidUploadKey/nar_key,_narinfo_type722=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type723=== RUN TestIsValidUploadKey/listing_key,_narinfo_type724=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type725=== RUN TestIsValidUploadKey/traversal726=== PAUSE TestIsValidUploadKey/traversal727=== RUN TestIsValidUploadKey/traversal_nar728=== PAUSE TestIsValidUploadKey/traversal_nar729=== RUN TestIsValidUploadKey/absolute730=== PAUSE TestIsValidUploadKey/absolute731=== RUN TestIsValidUploadKey/empty_key732=== PAUSE TestIsValidUploadKey/empty_key733=== RUN TestIsValidUploadKey/unknown_type734=== PAUSE TestIsValidUploadKey/unknown_type735=== CONT TestRedundantMultipartUpload736--- PASS: TestSkippedUploadsHandler (0.10s)737=== CONT TestReadRedirectUsesPublicS3URL738--- PASS: TestGracefulShutdownDrainsInflight (0.16s)739=== CONT TestClientErrorHandling740=== RUN TestClientErrorHandling/InvalidStorePath741=== PAUSE TestClientErrorHandling/InvalidStorePath742=== RUN TestClientErrorHandling/InvalidAuthToken743=== PAUSE TestClientErrorHandling/InvalidAuthToken744=== RUN TestClientErrorHandling/ServerNotAvailable745=== PAUSE TestClientErrorHandling/ServerNotAvailable746=== CONT TestLeadEndsOnShutdown747=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure748=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure749=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart750=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart751=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts752=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts753=== CONT TestLeadElectsOneAndHandsOver7542026-09-21 14:12:15.134 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367552026-09-21 14:12:15.134 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7562026-09-21 14:12:15.194 UTC [647] ERROR: relation "goose_db_version" does not exist at character 367572026-09-21 14:12:15.194 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026-09-21 14:12:15.206 UTC [648] ERROR: relation "goose_db_version" does not exist at character 367592026-09-21 14:12:15.206 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7602026-09-21 14:12:15.214 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367612026-09-21 14:12:15.214 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7622026/09/21 14:12:15 OK 20241026095416_initial_model.sql (27.78ms)7632026-09-21 14:12:15.251 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367642026-09-21 14:12:15.251 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026/09/21 14:12:15 OK 20241026095416_initial_model.sql (20.39ms)7662026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (4.94ms)7672026/09/21 14:12:15 OK 20241026095416_initial_model.sql (45.28ms)7682026/09/21 14:12:15 OK 20241026095416_initial_model.sql (18.94ms)7692026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)7702026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)7712026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (4.74ms)7722026/09/21 14:12:15 OK 20251218171726_add_pins.sql (5.76ms)7732026/09/21 14:12:15 OK 20251218171726_add_pins.sql (4.19ms)7742026/09/21 14:12:15 OK 20251218171726_add_pins.sql (5.29ms)7752026-09-21 14:12:15.265 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367762026-09-21 14:12:15.265 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-09-21 14:12:15.265 UTC [652] ERROR: relation "goose_db_version" does not exist at character 367782026-09-21 14:12:15.265 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)7802026/09/21 14:12:15 OK 20251218171726_add_pins.sql (8.73ms)7812026-09-21 14:12:15.269 UTC [654] ERROR: relation "goose_db_version" does not exist at character 367822026-09-21 14:12:15.269 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (7.43ms)7842026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (7.04ms)7852026-09-21 14:12:15.272 UTC [653] ERROR: relation "goose_db_version" does not exist at character 367862026-09-21 14:12:15.272 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026/09/21 14:12:15 OK 20260905000000_add_claims.sql (6.75ms)7882026/09/21 14:12:15 OK 20260905000000_add_claims.sql (5.22ms)7892026/09/21 14:12:15 OK 20260905000000_add_claims.sql (7.44ms)7902026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (4.65ms)7912026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000007922026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (10.34ms)7932026-09-21 14:12:15.284 UTC [655] ERROR: relation "goose_db_version" does not exist at character 367942026-09-21 14:12:15.284 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026-09-21 14:12:15.289 UTC [656] ERROR: relation "goose_db_version" does not exist at character 367962026-09-21 14:12:15.289 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (13.33ms)7982026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000007992026/09/21 14:12:15 OK 1_commit_pending_closure.sql (16.05ms)8002026/09/21 14:12:15 OK 20241026095416_initial_model.sql (33.47ms)8012026/09/21 14:12:15 OK 20260905000000_add_claims.sql (15.39ms)8022026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (17.81ms)8032026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000008042026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.65ms)8052026/09/21 14:12:15 goose: up to current file version: 28062026/09/21 14:12:15 OK 1_commit_pending_closure.sql (7.63ms)8072026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (4.06ms)8082026/09/21 14:12:15 OK 1_commit_pending_closure.sql (4.6ms)8092026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (6.04ms)8102026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000008112026/09/21 14:12:15 OK 2_object_stats_trigger.sql (3.96ms)8122026/09/21 14:12:15 goose: up to current file version: 28132026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.57ms)8142026/09/21 14:12:15 goose: up to current file version: 28152026/09/21 14:12:15 OK 1_commit_pending_closure.sql (4.61ms)8162026-09-21 14:12:15.306 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368172026-09-21 14:12:15.306 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/09/21 14:12:15 OK 20241026095416_initial_model.sql (33.19ms)8192026/09/21 14:12:15 OK 2_object_stats_trigger.sql (5.53ms)8202026/09/21 14:12:15 goose: up to current file version: 28212026/09/21 14:12:15 OK 20251218171726_add_pins.sql (13.96ms)8222026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)8232026/09/21 14:12:15 OK 20241026095416_initial_model.sql (35.63ms)8242026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)8252026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (8.13ms)8262026/09/21 14:12:15 OK 20251218171726_add_pins.sql (7.99ms)8272026/09/21 14:12:15 OK 20241026095416_initial_model.sql (27.84ms)8282026/09/21 14:12:15 OK 20241026095416_initial_model.sql (45.9ms)8292026/09/21 14:12:15 OK 20260905000000_add_claims.sql (15.29ms)8302026/09/21 14:12:15 OK 20251218171726_add_pins.sql (16.84ms)8312026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (15.28ms)8322026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (12.93ms)8332026/09/21 14:12:15 OK 20241026095416_initial_model.sql (28.32ms)8342026/09/21 14:12:15 OK 20241026095416_initial_model.sql (18.32ms)8352026/09/21 14:12:15 OK 20241026095416_initial_model.sql (31.88ms)8362026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (14.56ms)8372026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (6.47ms)8382026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000008392026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (3.94ms)8402026/09/21 14:12:15 OK 20260905000000_add_claims.sql (9.58ms)8412026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (5.48ms)8422026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (5.42ms)8432026/09/21 14:12:15 OK 1_commit_pending_closure.sql (4.66ms)8442026/09/21 14:12:15 OK 20251218171726_add_pins.sql (11.11ms)8452026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (4.48ms)8462026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (14.31ms)8472026/09/21 14:12:15 OK 20251218171726_add_pins.sql (9.81ms)8482026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000008492026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.9ms)8502026/09/21 14:12:15 goose: up to current file version: 28512026/09/21 14:12:15 OK 20251218171726_add_pins.sql (5.8ms)8522026-09-21 14:12:15.351 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368532026-09-21 14:12:15.351 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026/09/21 14:12:15 OK 20251218171726_add_pins.sql (5.58ms)8552026/09/21 14:12:15 OK 20251218171726_add_pins.sql (5.83ms)8562026-09-21 14:12:15.353 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368572026-09-21 14:12:15.353 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026-09-21 14:12:15.355 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368592026-09-21 14:12:15.355 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8602026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)8612026/09/21 14:12:15 OK 20260905000000_add_claims.sql (5.33ms)8622026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)8632026/09/21 14:12:15 OK 1_commit_pending_closure.sql (5.11ms)8642026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)8652026-09-21 14:12:15.357 UTC [662] ERROR: relation "goose_db_version" does not exist at character 368662026-09-21 14:12:15.357 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC867--- PASS: TestReadProxyInvalidPath (0.42s)868=== CONT TestResolveDBConnectionString8692026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (6.61ms)870=== RUN TestResolveDBConnectionString/flag_wins871=== PAUSE TestResolveDBConnectionString/flag_wins872=== RUN TestResolveDBConnectionString/file_when_flag_empty873=== PAUSE TestResolveDBConnectionString/file_when_flag_empty874=== RUN TestResolveDBConnectionString/missing_file_is_an_error875=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error876=== RUN TestResolveDBConnectionString/PGHOST_allows_empty877=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty878=== RUN TestResolveDBConnectionString/nothing_configured879=== PAUSE TestResolveDBConnectionString/nothing_configured8802026/09/21 14:12:15 OK 2_object_stats_trigger.sql (3.17ms)881=== CONT TestPinProtectsFromGC8822026/09/21 14:12:15 goose: up to current file version: 28832026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.29ms)8842026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.49ms)8852026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (8.86ms)8862026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (4.87ms)8872026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000008882026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.18ms)8892026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000008902026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (3.25ms)8912026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000008922026/09/21 14:12:15 OK 20260905000000_add_claims.sql (4.64ms)8932026/09/21 14:12:15 OK 20260905000000_add_claims.sql (7.01ms)8942026-09-21 14:12:15.365 UTC [663] ERROR: relation "goose_db_version" does not exist at character 368952026-09-21 14:12:15.365 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8962026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.66ms)8972026-09-21 14:12:15.365 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368982026-09-21 14:12:15.365 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.7ms)9002026/09/21 14:12:15 OK 1_commit_pending_closure.sql (4.83ms)9012026/09/21 14:12:15 OK 20260905000000_add_claims.sql (6.15ms)9022026-09-21 14:12:15.367 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369032026-09-21 14:12:15.367 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9042026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (3.25ms)9052026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000009062026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.08ms)9072026/09/21 14:12:15 goose: up to current file version: 29082026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.96ms)9092026/09/21 14:12:15 goose: up to current file version: 29102026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.37ms)9112026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (5.35ms)9122026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000009132026/09/21 14:12:15 OK 2_object_stats_trigger.sql (3.11ms)9142026/09/21 14:12:15 goose: up to current file version: 29152026-09-21 14:12:15.370 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369162026-09-21 14:12:15.370 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026/09/21 14:12:15 OK 1_commit_pending_closure.sql (3.41ms)9182026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)9192026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (4.5ms)9202026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000009212026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.74ms)9222026/09/21 14:12:15 goose: up to current file version: 29232026-09-21 14:12:15.373 UTC [669] ERROR: relation "goose_db_version" does not exist at character 369242026-09-21 14:12:15.373 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026-09-21 14:12:15.373 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369262026-09-21 14:12:15.373 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026/09/21 14:12:15 OK 1_commit_pending_closure.sql (4.82ms)9282026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.03ms)9292026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.36ms)9302026/09/21 14:12:15 OK 20251218171726_add_pins.sql (4.25ms)9312026/09/21 14:12:15 OK 20241026095416_initial_model.sql (11.21ms)9322026/09/21 14:12:15 OK 1_commit_pending_closure.sql (4.81ms)9332026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2ms)9342026/09/21 14:12:15 goose: up to current file version: 29352026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)9362026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)9372026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)9382026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.88ms)9392026/09/21 14:12:15 goose: up to current file version: 29402026-09-21 14:12:15.380 UTC [672] ERROR: relation "goose_db_version" does not exist at character 369412026-09-21 14:12:15.380 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9422026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.7ms)9432026-09-21 14:12:15.380 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369442026-09-21 14:12:15.380 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9452026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)9462026/09/21 14:12:15 OK 20251218171726_add_pins.sql (4.76ms)9472026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.48ms)9482026/09/21 14:12:15 OK 20251218171726_add_pins.sql (4.52ms)9492026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.16ms)9502026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)9512026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.38ms)9522026/09/21 14:12:15 OK 20241026095416_initial_model.sql (9.46ms)9532026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)9542026/09/21 14:12:15 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"955--- PASS: TestService_AuthMiddleware (0.45s)956=== CONT TestClientSharedPathCommittedMidPush9572026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)9582026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)9592026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)9602026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.86ms)9612026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000009622026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.87ms)9632026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.48ms)9642026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)9652026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.55ms)9662026/09/21 14:12:15 OK 20260905000000_add_claims.sql (4.22ms)9672026/09/21 14:12:15 OK 20251218171726_add_pins.sql (4.05ms)9682026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)9692026/09/21 14:12:15 OK 20260905000000_add_claims.sql (4.49ms)9702026/09/21 14:12:15 OK 1_commit_pending_closure.sql (3.68ms)9712026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.79ms)9722026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000009732026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)9742026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.9ms)9752026/09/21 14:12:15 OK 20260905000000_add_claims.sql (4.14ms)9762026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)9772026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.84ms)9782026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.78ms)9792026/09/21 14:12:15 goose: up to current file version: 29802026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)9812026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)9822026/09/21 14:12:15 OK 20251218171726_add_pins.sql (4.17ms)9832026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (3.64ms)9842026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000009852026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.58ms)9862026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000009872026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.06ms)9882026/09/21 14:12:15 OK 1_commit_pending_closure.sql (3.19ms)9892026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)9902026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.24ms)9912026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.06ms)9922026/09/21 14:12:15 goose: up to current file version: 29932026/09/21 14:12:15 OK 20260905000000_add_claims.sql (4.14ms)9942026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.13ms)9952026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.25ms)9962026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.87ms)9972026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)9982026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.81ms)9992026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010002026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.55ms)10012026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.6ms)10022026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.81ms)10032026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)10042026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.48ms)10052026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010062026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.42ms)10072026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)10082026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.31ms)10092026/09/21 14:12:15 goose: up to current file version: 210102026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.81ms)10112026/09/21 14:12:15 goose: up to current file version: 210122026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.84ms)10132026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010142026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.82ms)10152026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.25ms)10162026/09/21 14:12:15 goose: up to current file version: 210172026/09/21 14:12:15 OK 20260905000000_add_claims.sql (4.43ms)10182026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)10192026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (5.27ms)10202026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.72ms)10212026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.65ms)10222026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.26ms)10232026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.48ms)10242026/09/21 14:12:15 goose: up to current file version: 210252026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.45ms)10262026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010272026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.8ms)10282026/09/21 14:12:15 goose: up to current file version: 210292026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)10302026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.98ms)10312026/09/21 14:12:15 OK 20260905000000_add_claims.sql (4.15ms)10322026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.82ms)10332026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)10342026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.47ms)10352026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (3.01ms)10362026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010372026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (3.2ms)10382026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010392026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.04ms)10402026/09/21 14:12:15 goose: up to current file version: 210412026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.61ms)10422026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.15ms)10432026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010442026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.26ms)10452026/09/21 14:12:15 OK 1_commit_pending_closure.sql (3.32ms)10462026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (3.08ms)10472026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010482026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.73ms)10492026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.94ms)10502026/09/21 14:12:15 goose: up to current file version: 210512026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.84ms)10522026/09/21 14:12:15 goose: up to current file version: 210532026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.06ms)10542026/09/21 14:12:15 goose: up to current file version: 210552026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.25ms)1056--- PASS: TestService_Rustfstest (0.48s)1057=== CONT TestClientWithDependencies10582026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.53ms)10592026/09/21 14:12:15 goose: up to current file version: 210602026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures10612026/09/21 14:12:15 INFO Received cleanup request method=DELETE path=/api/pending_closures10622026/09/21 14:12:15 INFO Aborted multipart uploads count=010632026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures1064--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.54s)1065=== CONT TestClientMultipleUploads10662026-09-21 14:12:15.480 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3610672026-09-21 14:12:15.480 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10682026/09/21 14:12:15 INFO Received cleanup request method=DELETE path=/api/pending_closures10692026/09/21 14:12:15 INFO Aborted multipart uploads count=110702026/09/21 14:12:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10712026-09-21 14:12:15.490 UTC [652] ERROR: Closure does not exist: id=110722026-09-21 14:12:15.490 UTC [652] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10732026-09-21 14:12:15.490 UTC [652] STATEMENT: -- name: CommitPendingClosure :exec1074 SELECT commit_pending_closure($1::bigint)1075 10762026/09/21 14:12:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1077--- PASS: TestService_cleanupPendingClosuresHandler (0.55s)1078=== CONT TestClientIntegration10792026-09-21 14:12:15.490 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3610802026-09-21 14:12:15.490 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10812026/09/21 14:12:15 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1082--- PASS: TestCompleteMultipartUnregistered (0.55s)1083=== CONT TestReadProxyDisabled10842026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.37ms)10852026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)10862026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.52ms)10872026/09/21 14:12:15 OK 20241026095416_initial_model.sql (8.59ms)10882026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)10892026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)10902026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.74ms)10912026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.26ms)10922026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)10932026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (4.3ms)10942026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010952026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.95ms)10962026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.57ms)10972026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000010982026/09/21 14:12:15 OK 1_commit_pending_closure.sql (3.52ms)10992026-09-21 14:12:15.520 UTC [685] ERROR: relation "goose_db_version" does not exist at character 3611002026-09-21 14:12:15.520 UTC [685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11012026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.34ms)11022026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.9ms)11032026/09/21 14:12:15 goose: up to current file version: 211042026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures11052026/09/21 14:12:15 OK 2_object_stats_trigger.sql (2.22ms)11062026/09/21 14:12:15 goose: up to current file version: 211072026/09/21 14:12:15 OK 20241026095416_initial_model.sql (10.31ms)11082026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)11092026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.85ms)11102026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)11112026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures11122026/09/21 14:12:15 OK 20260905000000_add_claims.sql (12.16ms)11132026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (4.92ms)11142026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000011152026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.51ms)11162026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.9ms)11172026/09/21 14:12:15 goose: up to current file version: 211182026-09-21 14:12:15.570 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3611192026-09-21 14:12:15.570 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11202026-09-21 14:12:15.580 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3611212026-09-21 14:12:15.580 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1122--- PASS: TestGCBugBareHashReferences (0.64s)1123=== CONT TestReadRedirectKeepsNarinfoProxied11242026/09/21 14:12:15 OK 20241026095416_initial_model.sql (7.36ms)11252026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (897.86µs)11262026-09-21 14:12:15.586 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3611272026-09-21 14:12:15.586 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11282026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.88ms)11292026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (2.52ms)11302026/09/21 14:12:15 OK 20241026095416_initial_model.sql (8.28ms)11312026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.97ms)11322026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)11332026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.2ms)11342026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000011352026/09/21 14:12:15 OK 20251218171726_add_pins.sql (3.45ms)1136--- PASS: TestMetricsInventory (0.65s)11372026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.41ms)1138=== CONT TestReadRedirectNar11392026/09/21 14:12:15 OK 20241026095416_initial_model.sql (8.33ms)11402026/09/21 14:12:15 OK 2_object_stats_trigger.sql (808.42µs)11412026/09/21 14:12:15 goose: up to current file version: 211422026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)11432026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (2.66ms)11442026/09/21 14:12:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11452026/09/21 14:12:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1146--- PASS: TestService_NativeMTLS (0.67s)1147=== CONT TestReadProxyConditionalGet11482026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.95ms)11492026/09/21 14:12:15 OK 20251218171726_add_pins.sql (5.51ms)11502026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.67ms)11512026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000011522026/09/21 14:12:15 OK 1_commit_pending_closure.sql (3.21ms)11532026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (6.05ms)11542026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.7ms)11552026/09/21 14:12:15 goose: up to current file version: 211562026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.08ms)11572026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.54ms)11582026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000011592026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.64ms)11602026/09/21 14:12:15 OK 2_object_stats_trigger.sql (1.75ms)11612026/09/21 14:12:15 goose: up to current file version: 211622026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures11632026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures11652026/09/21 14:12:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11662026-09-21 14:12:15.666 UTC [695] ERROR: relation "goose_db_version" does not exist at character 3611672026-09-21 14:12:15.666 UTC [695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11682026/09/21 14:12:15 OK 20241026095416_initial_model.sql (7.92ms)11692026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)11702026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures11712026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.18ms)11722026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (2.6ms)11732026-09-21 14:12:15.696 UTC [697] ERROR: relation "goose_db_version" does not exist at character 3611742026-09-21 14:12:15.696 UTC [697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.97ms)11762026-09-21 14:12:15.700 UTC [706] ERROR: relation "goose_db_version" does not exist at character 3611772026-09-21 14:12:15.700 UTC [706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11782026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (2.25ms)11792026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000011802026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.04ms)11812026/09/21 14:12:15 OK 2_object_stats_trigger.sql (867.43µs)11822026/09/21 14:12:15 goose: up to current file version: 211832026/09/21 14:12:15 OK 20241026095416_initial_model.sql (7.66ms)1184=== NAME TestNARDeduplicationMetadataUploadBug1185 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3313019482/001/store/xrzzckdjlxal17z929m99aa608bj01q5-file1.txt11862026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)11872026/09/21 14:12:15 OK 20241026095416_initial_model.sql (7.38ms)11882026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.05ms)11892026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)11902026/09/21 14:12:15 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11912026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures11922026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (2.98ms)11932026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.35ms)1194--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.68s)1195=== CONT TestReadProxyRootRedirectsToIndexHTML11962026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.2ms)11972026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (2.25ms)11982026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (1.73ms)11992026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000001200--- PASS: TestService_healthCheckHandler (0.69s)1201=== CONT TestReadProxyHead12022026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.73ms)12032026/09/21 14:12:15 OK 1_commit_pending_closure.sql (1.63ms)12042026/09/21 14:12:15 OK 2_object_stats_trigger.sql (838.24µs)12052026/09/21 14:12:15 goose: up to current file version: 212062026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (1.47ms)12072026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000012082026/09/21 14:12:15 OK 1_commit_pending_closure.sql (1.39ms)12092026/09/21 14:12:15 OK 2_object_stats_trigger.sql (746.82µs)12102026/09/21 14:12:15 goose: up to current file version: 212112026/09/21 14:12:15 WARN readiness check failed error="closed pool"1212--- PASS: TestService_readinessHandler (0.71s)1213=== CONT TestParseSingleRange1214=== RUN TestParseSingleRange/none1215=== PAUSE TestParseSingleRange/none1216=== RUN TestParseSingleRange/unknown_unit1217=== PAUSE TestParseSingleRange/unknown_unit1218=== RUN TestParseSingleRange/multi-range_ignored1219=== PAUSE TestParseSingleRange/multi-range_ignored1220=== RUN TestParseSingleRange/malformed_no_dash1221=== PAUSE TestParseSingleRange/malformed_no_dash1222=== RUN TestParseSingleRange/malformed_both_empty1223=== PAUSE TestParseSingleRange/malformed_both_empty1224=== RUN TestParseSingleRange/malformed_end_before_start1225=== PAUSE TestParseSingleRange/malformed_end_before_start1226=== RUN TestParseSingleRange/closed1227=== PAUSE TestParseSingleRange/closed1228=== RUN TestParseSingleRange/open-ended1229=== PAUSE TestParseSingleRange/open-ended1230=== RUN TestParseSingleRange/end_clamped_to_size1231=== PAUSE TestParseSingleRange/end_clamped_to_size1232=== RUN TestParseSingleRange/suffix1233=== PAUSE TestParseSingleRange/suffix1234=== RUN TestParseSingleRange/suffix_exceeds_size1235=== PAUSE TestParseSingleRange/suffix_exceeds_size1236=== RUN TestParseSingleRange/single_byte1237=== PAUSE TestParseSingleRange/single_byte1238=== RUN TestParseSingleRange/start_past_EOF1239=== PAUSE TestParseSingleRange/start_past_EOF1240=== RUN TestParseSingleRange/start_far_past_EOF1241=== PAUSE TestParseSingleRange/start_far_past_EOF1242=== CONT TestReadProxy40412432026/09/21 14:12:15 INFO lead: acquired remote=192.0.2.1:123412442026/09/21 14:12:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12452026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures12462026-09-21 14:12:15.804 UTC [759] ERROR: relation "goose_db_version" does not exist at character 3612472026-09-21 14:12:15.804 UTC [759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12482026-09-21 14:12:15.818 UTC [760] ERROR: relation "goose_db_version" does not exist at character 3612492026-09-21 14:12:15.818 UTC [760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12502026/09/21 14:12:15 OK 20241026095416_initial_model.sql (8.26ms)12512026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)12522026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.77ms)12532026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)12542026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures12552026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.84ms)12562026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures12572026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (9.01ms)12582026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000012592026/09/21 14:12:15 OK 20241026095416_initial_model.sql (14.41ms)12602026/09/21 14:12:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12612026/09/21 14:12:15 INFO Uploading xrzzckdjlxal17z929m99aa608bj01q5-file1.txt (160B)12622026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)12632026/09/21 14:12:15 OK 1_commit_pending_closure.sql (1.78ms)12642026/09/21 14:12:15 OK 2_object_stats_trigger.sql (916.16µs)12652026/09/21 14:12:15 goose: up to current file version: 212662026/09/21 14:12:15 OK 20251218171726_add_pins.sql (1.98ms)12672026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)12682026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures12692026-09-21 14:12:15.849 UTC [778] ERROR: relation "goose_db_version" does not exist at character 3612702026-09-21 14:12:15.849 UTC [778] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12712026/09/21 14:12:15 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12722026/09/21 14:12:15 OK 20260905000000_add_claims.sql (2.18ms)12732026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (1.65ms)12742026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000012752026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.58ms)12762026/09/21 14:12:15 WARN Failed to register uploaded object key=xrzzckdjlxal17z929m99aa608bj01q5.ls error="server returned 404: 404 page not found\n"12772026/09/21 14:12:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12782026/09/21 14:12:15 OK 2_object_stats_trigger.sql (805.37µs)12792026/09/21 14:12:15 goose: up to current file version: 212802026/09/21 14:12:15 INFO Signed narinfos id=1 count=112812026/09/21 14:12:15 INFO Uploading 1 narinfos12822026/09/21 14:12:15 INFO Received uploads request method=POST path=/api/pending_closures12832026/09/21 14:12:15 OK 20241026095416_initial_model.sql (8.33ms)12842026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)12852026/09/21 14:12:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12862026/09/21 14:12:15 WARN Failed to register uploaded object key=xrzzckdjlxal17z929m99aa608bj01q5.narinfo error="server returned 404: 404 page not found\n"12872026/09/21 14:12:15 OK 20251218171726_add_pins.sql (2.1ms)12882026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (2.44ms)12892026/09/21 14:12:15 INFO Completed upload id=112902026/09/21 14:12:15 INFO Upload complete. (121ms)12912026/09/21 14:12:15 OK 20260905000000_add_claims.sql (3.01ms)12922026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (1.73ms)12932026/09/21 14:12:15 goose: successfully migrated database to version: 202609200000001294=== NAME TestNARDeduplicationMetadataUploadBug1295 metadata_upload_test.go:54: Retrieved narinfo from S3:1296 StorePath: /build/TestNARDeduplicationMetadataUploadBug3313019482/001/store/xrzzckdjlxal17z929m99aa608bj01q5-file1.txt1297 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1298 Compression: zstd1299 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1300 NarSize: 1601301 References: 1302 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13032026/09/21 14:12:15 OK 1_commit_pending_closure.sql (1.62ms)13042026/09/21 14:12:15 OK 2_object_stats_trigger.sql (827.59µs)13052026/09/21 14:12:15 goose: up to current file version: 21306 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1307 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1308 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13092026/09/21 14:12:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13102026/09/21 14:12:15 INFO Aborted multipart uploads count=013112026/09/21 14:12:15 WARN Force mode enabled - objects will be deleted immediately without grace period13122026/09/21 14:12:15 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWQxMzkwNTMtOGNlYy00NDQ1LTk1NTEtZGFmMGY0YTNiZTI0Ljg4MjE2ODE4LWZhMGUtNGU4Zi04ZjE2LTIxZjkwNWNkYmI5NHgxNzg5OTk5OTM1ODY5MDAyMzU113132026/09/21 14:12:15 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=013142026/09/21 14:12:15 INFO Vacuumed table table=pending_closures13152026/09/21 14:12:15 INFO Vacuumed table table=pending_objects13162026/09/21 14:12:15 INFO Vacuumed table table=multipart_uploads13172026/09/21 14:12:15 INFO Vacuumed table table=closures13182026/09/21 14:12:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWQxMzkwNTMtOGNlYy00NDQ1LTk1NTEtZGFmMGY0YTNiZTI0Ljg4MjE2ODE4LWZhMGUtNGU4Zi04ZjE2LTIxZjkwNWNkYmI5NHgxNzg5OTk5OTM1ODY5MDAyMzU1 parts=113192026/09/21 14:12:15 INFO Vacuumed table table=objects1320--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.87s)1321=== CONT TestReadProxyNarStreaming1322--- PASS: TestGCMetrics (0.88s)1323=== CONT TestReadProxyNarinfoAlreadyDecompressed1324=== NAME TestNARDeduplicationMetadataUploadBug1325 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3313019482/001/store/l7697n8dkw80lvx5a1kl1y65mmm50g2h-file2.txt1326--- PASS: TestReadProxyRangeRequest (0.89s)13272026/09/21 14:12:15 INFO lead: released remote=192.0.2.1:12341328=== CONT TestReadProxyNarinfo13292026/09/21 14:12:15 INFO lead: acquired remote=192.0.2.1:123413302026/09/21 14:12:15 INFO lead: released remote=192.0.2.1:12341331--- PASS: TestLeadEndsOnShutdown (0.84s)1332=== CONT TestIsValidCachePath1333=== RUN TestIsValidCachePath/narinfo1334=== PAUSE TestIsValidCachePath/narinfo1335=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1336=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1337=== RUN TestIsValidCachePath/nar_zst1338=== PAUSE TestIsValidCachePath/nar_zst1339=== RUN TestIsValidCachePath/nar_xz1340=== PAUSE TestIsValidCachePath/nar_xz1341=== RUN TestIsValidCachePath/nar_bz21342=== PAUSE TestIsValidCachePath/nar_bz21343=== RUN TestIsValidCachePath/nar_uncompressed1344=== PAUSE TestIsValidCachePath/nar_uncompressed1345=== RUN TestIsValidCachePath/ls1346=== PAUSE TestIsValidCachePath/ls1347=== RUN TestIsValidCachePath/log1348=== PAUSE TestIsValidCachePath/log1349=== RUN TestIsValidCachePath/realisation1350=== PAUSE TestIsValidCachePath/realisation1351=== RUN TestIsValidCachePath/nix-cache-info1352=== PAUSE TestIsValidCachePath/nix-cache-info1353=== RUN TestIsValidCachePath/index.html1354=== PAUSE TestIsValidCachePath/index.html1355=== RUN TestIsValidCachePath/traversal_parent1356=== PAUSE TestIsValidCachePath/traversal_parent1357=== RUN TestIsValidCachePath/traversal_in_middle1358=== PAUSE TestIsValidCachePath/traversal_in_middle1359=== RUN TestIsValidCachePath/invalid_char_e1360=== PAUSE TestIsValidCachePath/invalid_char_e1361=== RUN TestIsValidCachePath/invalid_char_u1362=== PAUSE TestIsValidCachePath/invalid_char_u1363=== RUN TestIsValidCachePath/random_path1364=== PAUSE TestIsValidCachePath/random_path1365=== RUN TestIsValidCachePath/empty1366=== PAUSE TestIsValidCachePath/empty1367=== RUN TestIsValidCachePath/leading_slash1368=== PAUSE TestIsValidCachePath/leading_slash1369=== RUN TestIsValidCachePath/wrong_extension1370=== PAUSE TestIsValidCachePath/wrong_extension1371=== RUN TestIsValidCachePath/short_hash1372=== PAUSE TestIsValidCachePath/short_hash1373=== CONT TestOrphanedObjectsGC13742026/09/21 14:12:15 INFO lead: acquired remote=192.0.2.1:123413752026/09/21 14:12:15 INFO lead: released remote=192.0.2.1:12341376--- PASS: TestLeadElectsOneAndHandsOver (0.87s)1377=== CONT TestResurrectedObjectNotDeleted1378--- PASS: TestReadRedirectUsesPublicS3URL (0.95s)1379=== CONT TestOrphanedObjectsGCStressTest13802026/09/21 14:12:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13812026-09-21 14:12:16.000 UTC [846] ERROR: relation "goose_db_version" does not exist at character 3613822026-09-21 14:12:16.000 UTC [846] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13832026/09/21 14:12:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13842026-09-21 14:12:16.016 UTC [850] ERROR: relation "goose_db_version" does not exist at character 3613852026-09-21 14:12:16.016 UTC [850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13862026/09/21 14:12:16 OK 20241026095416_initial_model.sql (20.07ms)13872026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)13882026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures13892026/09/21 14:12:16 OK 20251218171726_add_pins.sql (4.58ms)13902026/09/21 14:12:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWQxMzkwNTMtOGNlYy00NDQ1LTk1NTEtZGFmMGY0YTNiZTI0LjIxOTQwMmEzLTg1ZWUtNGE3YS1iNmE0LTFkYTY1Y2U1MjEwMXgxNzg5OTk5OTM1NTM3MTE0MDU0 parts=1013912026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13922026-09-21 14:12:16.037 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3613932026-09-21 14:12:16.037 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13942026/09/21 14:12:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13952026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)13962026/09/21 14:12:16 OK 20241026095416_initial_model.sql (10.04ms)13972026/09/21 14:12:16 INFO Completed upload id=113982026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.12ms)13992026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)14002026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures14012026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14022026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.11ms)14032026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000014042026/09/21 14:12:16 WARN Failed to register uploaded object key=l7697n8dkw80lvx5a1kl1y65mmm50g2h.ls error="server returned 404: 404 page not found\n"14052026/09/21 14:12:16 INFO Signed narinfos id=2 count=114062026/09/21 14:12:16 INFO Uploading 1 narinfos14072026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.74ms)14082026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures14092026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.34ms)14102026/09/21 14:12:16 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14112026/09/21 14:12:16 WARN Found objects in DB but missing from S3, will re-upload count=114122026/09/21 14:12:16 OK 2_object_stats_trigger.sql (2.1ms)14132026/09/21 14:12:16 goose: up to current file version: 214142026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)14152026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14162026/09/21 14:12:16 WARN Failed to register uploaded object key=l7697n8dkw80lvx5a1kl1y65mmm50g2h.narinfo error="server returned 404: 404 page not found\n"1417--- PASS: TestService_verifyS3Integrity (1.11s)1418=== CONT TestService_RequireScope_OIDC14192026/09/21 14:12:16 INFO Completed upload id=214202026/09/21 14:12:16 INFO Upload complete. (88ms)14212026/09/21 14:12:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44233/oidc14222026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.75ms)14232026/09/21 14:12:16 OK 20241026095416_initial_model.sql (9.81ms)1424=== NAME TestNARDeduplicationMetadataUploadBug1425 metadata_upload_test.go:76: Retrieved narinfo from S3:1426 StorePath: /build/TestNARDeduplicationMetadataUploadBug3313019482/001/store/l7697n8dkw80lvx5a1kl1y65mmm50g2h-file2.txt1427 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1428 Compression: zstd1429 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1430 NarSize: 1601431 References: 1432 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14332026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.73ms)14342026/09/21 14:12:16 goose: successfully migrated database to version: 202609200000001435 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)14362026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)1437 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1438 {"version":1,"root":{"type":"regular","size":44}}14392026-09-21 14:12:16.056 UTC [905] ERROR: relation "goose_db_version" does not exist at character 3614402026-09-21 14:12:16.056 UTC [905] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14412026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.62ms)14422026/09/21 14:12:16 OK 20251218171726_add_pins.sql (3.14ms)14432026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.6ms)14442026/09/21 14:12:16 goose: up to current file version: 214452026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)1446--- PASS: TestNARDeduplicationMetadataUploadBug (1.03s)1447=== CONT TestClientCADerivations14482026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.42ms)14492026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.63ms)14502026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000014512026/09/21 14:12:16 OK 20241026095416_initial_model.sql (9.16ms)14522026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.85ms)14532026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)14542026/09/21 14:12:16 OK 2_object_stats_trigger.sql (2.7ms)14552026/09/21 14:12:16 goose: up to current file version: 214562026/09/21 14:12:16 OK 20251218171726_add_pins.sql (3.32ms)14572026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)1458=== NAME TestPinProtectsFromGC1459 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC633238736/001/store/b5c3hx3f87jfdjmagj98yayg5l2my7fn-pinned-file.txt1460 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC633238736/001/store/qgmpn3ranjc7l9a6hdv6cznjxkv5fhlm-unpinned-file.txt14612026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.28ms)14622026-09-21 14:12:16.087 UTC [944] ERROR: relation "goose_db_version" does not exist at character 3614632026-09-21 14:12:16.087 UTC [944] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14642026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (3.02ms)14652026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000014662026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.16ms)14672026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.61ms)14682026/09/21 14:12:16 goose: up to current file version: 214692026-09-21 14:12:16.094 UTC [946] ERROR: relation "goose_db_version" does not exist at character 3614702026-09-21 14:12:16.094 UTC [946] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14712026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.38ms)14722026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)14732026/09/21 14:12:16 OK 20251218171726_add_pins.sql (3.13ms)14742026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.93ms)14752026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)14762026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)14772026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.13ms)14782026/09/21 14:12:16 OK 20251218171726_add_pins.sql (3.15ms)14792026/09/21 14:12:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14802026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (10.92ms)14812026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000014822026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (12.52ms)14832026/09/21 14:12:16 OK 1_commit_pending_closure.sql (3.93ms)14842026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.3ms)14852026/09/21 14:12:16 OK 2_object_stats_trigger.sql (2.49ms)14862026/09/21 14:12:16 goose: up to current file version: 214872026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (3.28ms)14882026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000014892026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.49ms)1490=== NAME TestClientMultipleUploads1491 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1123995366/001/store/g41m79j9qdchqiwvy818c4j2l64g2rw0-test-file-0.txt14922026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.04ms)14932026/09/21 14:12:16 goose: up to current file version: 214942026/09/21 14:12:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWQxMzkwNTMtOGNlYy00NDQ1LTk1NTEtZGFmMGY0YTNiZTI0LjI5NGNiOGI2LWJkNmEtNGM3ZC04ZDRlLTZhYmZjZDk5NWEyZngxNzg5OTk5OTM1NjQ4NTgzNDg4 parts=1014952026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14962026/09/21 14:12:16 INFO Completed upload id=114972026/09/21 14:12:16 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014982026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures14992026/09/21 14:12:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures1500--- PASS: TestReadProxyDisabled (0.65s)1501=== CONT TestCacheStatsHandler15022026-09-21 14:12:16.150 UTC [1035] ERROR: relation "goose_db_version" does not exist at character 3615032026-09-21 14:12:16.150 UTC [1035] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1504=== NAME TestClientWithDependencies1505 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3894073216/001/store/q2mdyj5k2jkjgj2rzy4p0sr0yg1di1qh-test-script15062026-09-21 14:12:16.156 UTC [1055] ERROR: relation "goose_db_version" does not exist at character 3615072026-09-21 14:12:16.156 UTC [1055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15082026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15092026/09/21 14:12:16 INFO Aborted multipart uploads count=015102026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.38ms)15112026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)15122026/09/21 14:12:16 OK 20251218171726_add_pins.sql (10.68ms)15132026/09/21 14:12:16 OK 20241026095416_initial_model.sql (14.82ms)15142026/09/21 14:12:16 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=015152026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)15162026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)15172026/09/21 14:12:16 INFO Vacuumed table table=pending_closures1518=== NAME TestClientMultipleUploads1519 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1123995366/001/store/kjpi1dgw84y1hb9m8im2i9yrc7b54hcn-test-file-1.txt15202026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.81ms)15212026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.16ms)15222026/09/21 14:12:16 INFO Vacuumed table table=pending_objects15232026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.33ms)15242026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015252026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)15262026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.47ms)1527=== NAME TestClientIntegration15282026/09/21 14:12:16 INFO Vacuumed table table=multipart_uploads1529 client_integration_test.go:286: Created store path: /build/TestClientIntegration1028688846/002/store/bc791fhq9jg3dhix40bghpa8s72wsxqn-test-file.txt15302026/09/21 14:12:16 OK 2_object_stats_trigger.sql (657.74µs)15312026/09/21 14:12:16 goose: up to current file version: 215322026/09/21 14:12:16 INFO Vacuumed table table=closures1533=== NAME TestClientWithDependencies1534 client_integration_test.go:615: Found 1 dependencies (including self)15352026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.16ms)15362026/09/21 14:12:16 INFO Vacuumed table table=objects15372026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (1.39ms)15382026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015392026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.8ms)15402026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures15412026/09/21 14:12:16 OK 2_object_stats_trigger.sql (667.71µs)15422026/09/21 14:12:16 goose: up to current file version: 21543--- PASS: TestReadRedirectKeepsNarinfoProxied (0.61s)1544=== CONT TestCacheConfigHandler1545=== RUN TestCacheConfigHandler/full_config,_no_issuer1546=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1547=== RUN TestCacheConfigHandler/no_cache_url_configured1548=== PAUSE TestCacheConfigHandler/no_cache_url_configured1549=== RUN TestCacheConfigHandler/no_signing_keys1550=== PAUSE TestCacheConfigHandler/no_signing_keys1551=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1552=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1553=== CONT TestService_ReadScope_PublicByDefault15542026/09/21 14:12:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15552026/09/21 14:12:16 INFO Uploading b5c3hx3f87jfdjmagj98yayg5l2my7fn-pinned-file.txt (128B)15562026/09/21 14:12:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001557--- PASS: TestService_createPendingClosureHandler (1.26s)1558=== CONT TestMultipartCleanup15592026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15602026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15612026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15622026/09/21 14:12:16 WARN Failed to register uploaded object key=b5c3hx3f87jfdjmagj98yayg5l2my7fn.ls error="server returned 404: 404 page not found\n"15632026/09/21 14:12:16 INFO Signed narinfos id=1 count=115642026/09/21 14:12:16 INFO Uploading 1 narinfos15652026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15662026/09/21 14:12:16 WARN Failed to register uploaded object key=b5c3hx3f87jfdjmagj98yayg5l2my7fn.narinfo error="server returned 404: 404 page not found\n"1567=== NAME TestClientMultipleUploads1568 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1123995366/001/store/7gpslnxl2jvlkfziikba2v7ii9m8vkrz-test-file-2.txt15692026/09/21 14:12:16 INFO Completed upload id=115702026/09/21 14:12:16 INFO Upload complete. (106ms)1571--- PASS: TestReadRedirectNar (0.62s)1572=== CONT TestObjectStatsTrigger15732026-09-21 14:12:16.239 UTC [1242] ERROR: relation "goose_db_version" does not exist at character 3615742026-09-21 14:12:16.239 UTC [1242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15752026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures15762026/09/21 14:12:16 OK 20241026095416_initial_model.sql (9.43ms)1577--- PASS: TestReadProxyConditionalGet (0.65s)1578=== CONT TestService_ReadAuthMiddleware15792026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)15802026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15812026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures15822026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15832026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.91ms)15842026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (11.03ms)15852026/09/21 14:12:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15862026/09/21 14:12:16 INFO Uploading q2mdyj5k2jkjgj2rzy4p0sr0yg1di1qh-test-script (136B)15872026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.93ms)15882026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.69ms)15892026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015902026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1591--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.56s)1592=== CONT TestServerTLSConfig1593=== RUN TestServerTLSConfig/no_client_CA15942026/09/21 14:12:16 WARN Failed to register uploaded object key=log/50wgs9z4kdwc9l122l73lyavzldj6f2f-test-script.drv error="server returned 404: 404 page not found\n"1595=== PAUSE TestServerTLSConfig/no_client_CA1596=== RUN TestServerTLSConfig/missing_CA_file1597=== PAUSE TestServerTLSConfig/missing_CA_file1598=== RUN TestServerTLSConfig/not_a_PEM_file1599=== PAUSE TestServerTLSConfig/not_a_PEM_file1600=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16012026/09/21 14:12:16 OK 1_commit_pending_closure.sql (3.61ms)16022026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.47ms)16032026/09/21 14:12:16 goose: up to current file version: 216042026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16052026/09/21 14:12:16 WARN Failed to register uploaded object key=q2mdyj5k2jkjgj2rzy4p0sr0yg1di1qh.ls error="server returned 404: 404 page not found\n"16062026/09/21 14:12:16 INFO Signed narinfos id=1 count=116072026/09/21 14:12:16 INFO Uploading 1 narinfos16082026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16092026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16102026/09/21 14:12:16 WARN Failed to register uploaded object key=q2mdyj5k2jkjgj2rzy4p0sr0yg1di1qh.narinfo error="server returned 404: 404 page not found\n"16112026-09-21 14:12:16.290 UTC [1354] ERROR: relation "goose_db_version" does not exist at character 3616122026-09-21 14:12:16.290 UTC [1354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16132026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures16142026/09/21 14:12:16 INFO Completed upload id=116152026/09/21 14:12:16 INFO Upload complete. (81ms)16162026-09-21 14:12:16.300 UTC [1373] ERROR: relation "goose_db_version" does not exist at character 3616172026-09-21 14:12:16.300 UTC [1373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1618=== NAME TestClientWithDependencies1619 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3894073216/001/store) requires matching store prefix16202026/09/21 14:12:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16212026/09/21 14:12:16 INFO Uploading bc791fhq9jg3dhix40bghpa8s72wsxqn-test-file.txt (152B)16222026/09/21 14:12:16 OK 20241026095416_initial_model.sql (10.68ms)16232026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16242026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)16252026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1626--- PASS: TestClientWithDependencies (0.89s)1627=== CONT TestService_AuthMiddleware_MTLSProxyHeader16282026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16292026/09/21 14:12:16 OK 20251218171726_add_pins.sql (3.26ms)16302026/09/21 14:12:16 WARN Failed to register uploaded object key=bc791fhq9jg3dhix40bghpa8s72wsxqn.ls error="server returned 404: 404 page not found\n"16312026/09/21 14:12:16 INFO Signed narinfos id=1 count=116322026/09/21 14:12:16 INFO Uploading 1 narinfos16332026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.97ms)16342026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16352026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)16362026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16372026/09/21 14:12:16 WARN Failed to register uploaded object key=bc791fhq9jg3dhix40bghpa8s72wsxqn.narinfo error="server returned 404: 404 page not found\n"16382026-09-21 14:12:16.317 UTC [1423] ERROR: relation "goose_db_version" does not exist at character 3616392026-09-21 14:12:16.317 UTC [1423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16402026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)16412026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures16422026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.87ms)1643--- PASS: TestReadProxyHead (0.60s)1644=== CONT TestService_AuthMiddleware_OIDC16452026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.97ms)16462026/09/21 14:12:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38391/oidc16472026/09/21 14:12:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16482026/09/21 14:12:16 INFO Uploading qgmpn3ranjc7l9a6hdv6cznjxkv5fhlm-unpinned-file.txt (128B)16492026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.34ms)16502026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000016512026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)16522026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.87ms)16532026/09/21 14:12:16 INFO Completed upload id=116542026/09/21 14:12:16 INFO Upload complete. (106ms)16552026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.34ms)16562026/09/21 14:12:16 goose: up to current file version: 216572026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.84ms)16582026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16592026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.27ms)16602026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000016612026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.32ms)16622026/09/21 14:12:16 WARN Failed to register uploaded object key=qgmpn3ranjc7l9a6hdv6cznjxkv5fhlm.ls error="server returned 404: 404 page not found\n"16632026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16642026/09/21 14:12:16 INFO Signed narinfos id=2 count=116652026/09/21 14:12:16 INFO Uploading 1 narinfos16662026/09/21 14:12:16 OK 1_commit_pending_closure.sql (4.62ms)16672026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (3.76ms)16682026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.6ms)16692026/09/21 14:12:16 goose: up to current file version: 216702026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.73ms)16712026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1672--- PASS: TestReadProxy404 (0.59s)16732026/09/21 14:12:16 WARN Failed to register uploaded object key=qgmpn3ranjc7l9a6hdv6cznjxkv5fhlm.narinfo error="server returned 404: 404 page not found\n"1674=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16752026/09/21 14:12:16 INFO Received uploads request method=POST path=/1676=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16772026/09/21 14:12:16 INFO Received request for more parts method=POST path=/1678=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16792026/09/21 14:12:16 INFO Received complete multipart upload request method=POST path=/1680=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16812026/09/21 14:12:16 INFO Received uploads request method=POST path=/1682--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1683 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1684 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1685 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1686 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1687=== CONT TestProxyWriteTimeout/narinfo1688=== CONT TestProxyWriteTimeout/10_GiB_nar1689=== CONT TestProxyWriteTimeout/1_GiB_nar1690=== CONT TestProxyWriteTimeout/unknown_size1691--- PASS: TestProxyWriteTimeout (0.00s)1692 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1693 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1694 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1695 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1696=== CONT TestIsValidUploadKey/narinfo1697=== CONT TestIsValidUploadKey/realisation_plus_in_output1698=== CONT TestIsValidUploadKey/unknown_type1699=== CONT TestIsValidUploadKey/empty_key1700=== CONT TestIsValidUploadKey/absolute1701=== CONT TestIsValidUploadKey/traversal_nar1702=== CONT TestIsValidUploadKey/traversal1703=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1704=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1705=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1706=== CONT TestIsValidUploadKey/index.html1707=== CONT TestIsValidUploadKey/nix-cache-info1708=== CONT TestIsValidUploadKey/build_log_home-manager_file1709=== CONT TestIsValidUploadKey/realisation1710=== CONT TestIsValidUploadKey/build_log_equals1711=== CONT TestIsValidUploadKey/build_log_question_mark1712=== CONT TestIsValidUploadKey/build_log_plus_in_name1713=== CONT TestIsValidUploadKey/nar_plain1714=== CONT TestIsValidUploadKey/build_log1715=== CONT TestIsValidUploadKey/listing1716=== CONT TestIsValidUploadKey/nar_xz1717=== CONT TestIsValidUploadKey/nar_zst1718--- PASS: TestIsValidUploadKey (0.01s)1719 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1720 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1721 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1722 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1723 --- PASS: TestIsValidUploadKey/absolute (0.00s)1724 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1725 --- PASS: TestIsValidUploadKey/traversal (0.00s)1726 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1728 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1729 --- PASS: TestIsValidUploadKey/index.html (0.00s)1730 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1731 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1732 --- PASS: TestIsValidUploadKey/realisation (0.00s)1733 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1734 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1735 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1736 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1737 --- PASS: TestIsValidUploadKey/build_log (0.00s)1738 --- PASS: TestIsValidUploadKey/listing (0.00s)1739 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1740 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)17412026/09/21 14:12:16 INFO Completed upload id=21742=== CONT TestClientErrorHandling/InvalidStorePath17432026/09/21 14:12:16 INFO Upload complete. (86ms)17442026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)17452026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures17462026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.69ms)17472026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures17482026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.43ms)17492026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000017502026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures17512026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.42ms)17522026/09/21 14:12:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17532026/09/21 14:12:16 INFO Uploading ib1wl5hbfyyc99hxivbv7yyav12viqrf-shared-dep (136B)17542026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures17552026/09/21 14:12:16 OK 2_object_stats_trigger.sql (2.45ms)17562026/09/21 14:12:16 goose: up to current file version: 217572026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17582026/09/21 14:12:16 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17592026/09/21 14:12:16 INFO Uploading 7gpslnxl2jvlkfziikba2v7ii9m8vkrz-test-file-2.txt (160B)17602026/09/21 14:12:16 INFO Uploading g41m79j9qdchqiwvy818c4j2l64g2rw0-test-file-0.txt (160B)17612026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17622026/09/21 14:12:16 INFO Uploading kjpi1dgw84y1hb9m8im2i9yrc7b54hcn-test-file-1.txt (160B)17632026/09/21 14:12:16 WARN Failed to register uploaded object key=ib1wl5hbfyyc99hxivbv7yyav12viqrf.ls error="server returned 404: 404 page not found\n"17642026/09/21 14:12:16 INFO Signed narinfos id=2 count=117652026/09/21 14:12:16 INFO Uploading 1 narinfos17662026/09/21 14:12:16 INFO All 1 paths already cached1767=== NAME TestClientIntegration1768 client_integration_test.go:312: Retrieved narinfo from S3:1769 StorePath: /build/TestClientIntegration1028688846/002/store/bc791fhq9jg3dhix40bghpa8s72wsxqn-test-file.txt1770 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1771 Compression: zstd1772 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11773 NarSize: 1521774 References: 1775 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117762026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17772026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17782026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17792026/09/21 14:12:16 WARN Failed to register uploaded object key=ib1wl5hbfyyc99hxivbv7yyav12viqrf.narinfo error="server returned 404: 404 page not found\n"17802026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1781 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1782 client_integration_test.go:313: Decompressed .ls content (64 bytes):1783 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1784 client_integration_test.go:316: Testing garbage collection...17852026/09/21 14:12:16 WARN Failed to register uploaded object key=g41m79j9qdchqiwvy818c4j2l64g2rw0.ls error="server returned 404: 404 page not found\n"1786--- PASS: TestReadProxyNarStreaming (0.47s)1787=== CONT TestClientErrorHandling/ServerNotAvailable17882026/09/21 14:12:16 WARN Failed to register uploaded object key=7gpslnxl2jvlkfziikba2v7ii9m8vkrz.ls error="server returned 404: 404 page not found\n"17892026/09/21 14:12:16 WARN Failed to register uploaded object key=kjpi1dgw84y1hb9m8im2i9yrc7b54hcn.ls error="server returned 404: 404 page not found\n"17902026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17912026/09/21 14:12:16 INFO Signed narinfos id=1 count=117922026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17932026/09/21 14:12:16 INFO Signed narinfos id=2 count=117942026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign17952026/09/21 14:12:16 INFO Signed narinfos id=3 count=117962026/09/21 14:12:16 INFO Uploading 3 narinfos17972026-09-21 14:12:16.376 UTC [1508] ERROR: relation "goose_db_version" does not exist at character 3617982026-09-21 14:12:16.376 UTC [1508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17992026/09/21 14:12:16 INFO Received create pin request method=POST path=/api/pins/myapp18002026/09/21 14:12:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18012026/09/21 14:12:16 INFO Completed upload id=218022026/09/21 14:12:16 INFO Upload complete. (97ms)18032026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures18042026/09/21 14:12:16 WARN Failed to register uploaded object key=7gpslnxl2jvlkfziikba2v7ii9m8vkrz.narinfo error="server returned 404: 404 page not found\n"18052026/09/21 14:12:16 WARN Failed to register uploaded object key=kjpi1dgw84y1hb9m8im2i9yrc7b54hcn.narinfo error="server returned 404: 404 page not found\n"18062026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18072026/09/21 14:12:16 WARN Failed to register uploaded object key=g41m79j9qdchqiwvy818c4j2l64g2rw0.narinfo error="server returned 404: 404 page not found\n"18082026/09/21 14:12:16 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18092026/09/21 14:12:16 INFO Uploading wkk10i7iff29n1ynl69rp462arg1isrz-top (224B)18102026/09/21 14:12:16 INFO Uploading ib1wl5hbfyyc99hxivbv7yyav12viqrf-shared-dep (136B)18112026-09-21 14:12:16.382 UTC [1511] ERROR: relation "goose_db_version" does not exist at character 3618122026-09-21 14:12:16.382 UTC [1511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18132026/09/21 14:12:16 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC633238736/001/store/b5c3hx3f87jfdjmagj98yayg5l2my7fn-pinned-file.txt narinfo_key=b5c3hx3f87jfdjmagj98yayg5l2my7fn.narinfo18142026/09/21 14:12:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures18152026/09/21 14:12:16 INFO Garbage collection started18162026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/1rnanw7m7r30s1kmgdv39llwzybqc2pdzg6sg5vi26bxzmzk23vh.nar.zst error="server returned 404: 404 page not found\n"18172026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18182026/09/21 14:12:16 INFO Completed upload id=118192026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18202026/09/21 14:12:16 INFO Completed upload id=218212026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18222026/09/21 14:12:16 WARN Failed to register uploaded object key=wkk10i7iff29n1ynl69rp462arg1isrz.ls error="server returned 404: 404 page not found\n"18232026/09/21 14:12:16 INFO Completed upload id=318242026/09/21 14:12:16 INFO Upload complete. (122ms)1825=== NAME TestClientMultipleUploads1826 client_integration_test.go:369: Uploaded 3 paths in 177.339518ms18272026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18282026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.72ms)18292026/09/21 14:12:16 WARN Failed to register uploaded object key=ib1wl5hbfyyc99hxivbv7yyav12viqrf.ls error="server returned 404: 404 page not found\n"18302026/09/21 14:12:16 INFO Signed narinfos id=3 count=118312026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18322026/09/21 14:12:16 INFO Signed narinfos id=1 count=118332026/09/21 14:12:16 INFO Uploading 2 narinfos18342026/09/21 14:12:16 INFO Aborted multipart uploads count=018352026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)18362026/09/21 14:12:16 OK 20251218171726_add_pins.sql (3.31ms)18372026/09/21 14:12:16 WARN Failed to register uploaded object key=ib1wl5hbfyyc99hxivbv7yyav12viqrf.narinfo error="server returned 404: 404 page not found\n"18382026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18392026/09/21 14:12:16 WARN Force mode enabled - objects will be deleted immediately without grace period18402026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.83ms)18412026/09/21 14:12:16 WARN Failed to register uploaded object key=wkk10i7iff29n1ynl69rp462arg1isrz.narinfo error="server returned 404: 404 page not found\n"18422026/09/21 14:12:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWQxMzkwNTMtOGNlYy00NDQ1LTk1NTEtZGFmMGY0YTNiZTI0LmNkYTVhY2U1LTc5NDktNGRlMy1hYTRmLTgzNjEzNWY0MmMxN3gxNzg5OTk5OTM1ODE3MDA3Mzc4 parts=1218432026/09/21 14:12:16 INFO Completed upload id=118442026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)18452026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18462026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures1847--- PASS: TestClientMultipleUploads (0.93s)18482026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)1849--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1850=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18512026/09/21 14:12:16 INFO Received uploads request method=POST path=/1852=== CONT TestClientErrorHandling/InvalidAuthToken18532026/09/21 14:12:16 INFO Completed upload id=318542026/09/21 14:12:16 INFO Upload complete. (239ms)18552026/09/21 14:12:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures18562026/09/21 14:12:16 INFO Garbage collection started18572026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.73ms)1858=== NAME TestClientSharedPathCommittedMidPush1859 client_integration_test.go:680: Retrieved narinfo from S3:1860 StorePath: /build/TestClientSharedPathCommittedMidPush1353550507/001/store/ib1wl5hbfyyc99hxivbv7yyav12viqrf-shared-dep1861 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1862 Compression: zstd1863 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821864 NarSize: 1361865 References: 18662026/09/21 14:12:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1867 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1868--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.37s)1869=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18702026/09/21 14:12:16 INFO Received request for more parts method=POST path=/18712026/09/21 14:12:16 OK 20260905000000_add_claims.sql (3.57ms)18722026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)18732026-09-21 14:12:16.407 UTC [1546] ERROR: relation "goose_db_version" does not exist at character 3618742026-09-21 14:12:16.407 UTC [1546] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1875=== NAME TestClientSharedPathCommittedMidPush1876 client_integration_test.go:680: Retrieved narinfo from S3:1877 StorePath: /build/TestClientSharedPathCommittedMidPush1353550507/001/store/wkk10i7iff29n1ynl69rp462arg1isrz-top1878 URL: nar/1rnanw7m7r30s1kmgdv39llwzybqc2pdzg6sg5vi26bxzmzk23vh.nar.zst1879 Compression: zstd1880 NarHash: sha256:1rnanw7m7r30s1kmgdv39llwzybqc2pdzg6sg5vi26bxzmzk23vh1881 NarSize: 2241882 References: /build/TestClientSharedPathCommittedMidPush1353550507/001/store/ib1wl5hbfyyc99hxivbv7yyav12viqrf-shared-dep1883 CA: text:sha256:122z5af2ns95hmddddwz84vrj6d9ii8a0knw5kzqz6b5pryzg4wv18842026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.96ms)18852026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000018862026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.82ms)18872026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.95ms)18882026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.03ms)18892026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000018902026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.72ms)18912026/09/21 14:12:16 goose: up to current file version: 218922026/09/21 14:12:16 INFO Aborted multipart uploads count=018932026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.33ms)18942026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.54ms)1895--- PASS: TestClientSharedPathCommittedMidPush (1.03s)18962026/09/21 14:12:16 goose: up to current file version: 21897=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18982026/09/21 14:12:16 INFO Received complete multipart upload request method=POST path=/18992026-09-21 14:12:16.417 UTC [1550] ERROR: relation "goose_db_version" does not exist at character 3619002026-09-21 14:12:16.417 UTC [1550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19012026/09/21 14:12:16 WARN Force mode enabled - objects will be deleted immediately without grace period19022026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.33ms)19032026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)19042026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.85ms)19052026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)19062026/09/21 14:12:16 OK 20241026095416_initial_model.sql (8.47ms)19072026/09/21 14:12:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWQxMzkwNTMtOGNlYy00NDQ1LTk1NTEtZGFmMGY0YTNiZTI0LmQ1Y2YxNjdhLWU1YTQtNDc2Ny1hZjVlLTJkZjAxNmU1NWM4ZngxNzg5OTk5OTM1ODQyNzQ2NjUy parts=1219082026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.92ms)19092026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)1910--- PASS: TestRedundantMultipartUpload (1.39s)1911=== CONT TestResolveDBConnectionString/flag_wins1912=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1913=== CONT TestResolveDBConnectionString/nothing_configured1914=== CONT TestResolveDBConnectionString/missing_file_is_an_error1915=== CONT TestResolveDBConnectionString/file_when_flag_empty1916=== CONT TestParseSingleRange/none1917=== CONT TestParseSingleRange/open-ended1918=== CONT TestParseSingleRange/start_far_past_EOF1919=== CONT TestParseSingleRange/start_past_EOF1920=== CONT TestParseSingleRange/suffix_exceeds_size1921=== CONT TestParseSingleRange/suffix1922--- PASS: TestReadProxyNarinfo (0.51s)1923=== CONT TestParseSingleRange/single_byte19242026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (2.39ms)1925=== CONT TestParseSingleRange/malformed_both_empty19262026/09/21 14:12:16 goose: successfully migrated database to version: 202609200000001927=== CONT TestParseSingleRange/closed1928=== CONT TestParseSingleRange/multi-range_ignored1929=== CONT TestParseSingleRange/malformed_no_dash1930=== CONT TestParseSingleRange/unknown_unit19312026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.59ms)1932=== CONT TestParseSingleRange/end_clamped_to_size1933=== CONT TestParseSingleRange/malformed_end_before_start1934=== CONT TestIsValidCachePath/index.html1935=== CONT TestIsValidCachePath/short_hash1936=== CONT TestIsValidCachePath/wrong_extension1937--- PASS: TestResolveDBConnectionString (0.00s)1938 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1939 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1940 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1941 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1942 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1943=== CONT TestIsValidCachePath/narinfo1944=== CONT TestIsValidCachePath/empty1945=== CONT TestIsValidCachePath/random_path1946=== CONT TestIsValidCachePath/invalid_char_u1947=== CONT TestIsValidCachePath/leading_slash1948=== CONT TestIsValidCachePath/traversal_in_middle1949--- PASS: TestParseSingleRange (0.00s)1950 --- PASS: TestParseSingleRange/none (0.00s)1951 --- PASS: TestParseSingleRange/open-ended (0.00s)1952 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1953 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1954 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1955 --- PASS: TestParseSingleRange/suffix (0.00s)1956 --- PASS: TestParseSingleRange/single_byte (0.00s)1957 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1958 --- PASS: TestParseSingleRange/closed (0.00s)1959 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1960 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1961 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1962 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1963 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1964=== CONT TestIsValidCachePath/invalid_char_e1965=== CONT TestIsValidCachePath/realisation1966=== CONT TestIsValidCachePath/traversal_parent1967=== CONT TestIsValidCachePath/log1968=== CONT TestIsValidCachePath/ls1969=== CONT TestIsValidCachePath/nar_uncompressed1970=== CONT TestIsValidCachePath/nar_xz1971=== CONT TestIsValidCachePath/nar_bz21972=== CONT TestIsValidCachePath/nix-cache-info19732026/09/21 14:12:16 OK 1_commit_pending_closure.sql (2.48ms)1974=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1975=== CONT TestIsValidCachePath/nar_zst1976=== CONT TestCacheConfigHandler/full_config,_no_issuer1977=== CONT TestCacheConfigHandler/no_signing_keys1978=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1979--- PASS: TestIsValidCachePath (0.00s)1980 --- PASS: TestIsValidCachePath/index.html (0.00s)1981 --- PASS: TestIsValidCachePath/short_hash (0.00s)1982 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1983 --- PASS: TestIsValidCachePath/narinfo (0.00s)1984 --- PASS: TestIsValidCachePath/empty (0.00s)1985 --- PASS: TestIsValidCachePath/random_path (0.00s)1986 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1987 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1988 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1989 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1990 --- PASS: TestIsValidCachePath/realisation (0.00s)1991 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1992 --- PASS: TestIsValidCachePath/log (0.00s)1993 --- PASS: TestIsValidCachePath/ls (0.00s)1994 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1995 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1996 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1997 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1998 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1999 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2000=== CONT TestServerTLSConfig/no_client_CA2001=== CONT TestCacheConfigHandler/no_cache_url_configured2002=== CONT TestServerTLSConfig/not_a_PEM_file2003--- PASS: TestCacheConfigHandler (0.00s)2004 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2005 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2006 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2007 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)20082026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)2009=== CONT TestServerTLSConfig/missing_CA_file20102026-09-21 14:12:16.440 UTC [1552] ERROR: relation "goose_db_version" does not exist at character 3620112026-09-21 14:12:16.440 UTC [1552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20122026/09/21 14:12:16 OK 2_object_stats_trigger.sql (2.08ms)20132026/09/21 14:12:16 goose: up to current file version: 22014--- PASS: TestServerTLSConfig (0.00s)2015 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2016 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2017 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)20182026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.3ms)20192026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (1.71ms)20202026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000020212026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.31ms)20222026/09/21 14:12:16 OK 2_object_stats_trigger.sql (1.46ms)20232026/09/21 14:12:16 goose: up to current file version: 220242026/09/21 14:12:16 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20252026/09/21 14:12:16 OK 20241026095416_initial_model.sql (7.85ms)20262026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)20272026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.41ms)20282026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (2.82ms)20292026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.91ms)20302026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (8.68ms)20312026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000020322026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.39ms)20332026/09/21 14:12:16 OK 2_object_stats_trigger.sql (778.88µs)20342026/09/21 14:12:16 goose: up to current file version: 220352026-09-21 14:12:16.482 UTC [1570] ERROR: relation "goose_db_version" does not exist at character 3620362026-09-21 14:12:16.482 UTC [1570] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20372026/09/21 14:12:16 OK 20241026095416_initial_model.sql (6.9ms)20382026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)20392026/09/21 14:12:16 OK 20251218171726_add_pins.sql (2.05ms)20402026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (2.43ms)20412026/09/21 14:12:16 OK 20260905000000_add_claims.sql (2.38ms)20422026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (1.47ms)20432026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000020442026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.58ms)20452026/09/21 14:12:16 OK 2_object_stats_trigger.sql (735.12µs)20462026/09/21 14:12:16 goose: up to current file version: 22047--- PASS: TestResurrectedObjectNotDeleted (0.54s)20482026/09/21 14:12:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.014958ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2049=== RUN TestService_RequireScope_OIDC/builder_may_write2050=== PAUSE TestService_RequireScope_OIDC/builder_may_write2051=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2052=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2053=== RUN TestService_RequireScope_OIDC/ops_may_admin2054=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2055=== RUN TestService_RequireScope_OIDC/ops_may_not_write2056=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2057=== RUN TestService_RequireScope_OIDC/reader_may_not_write2058=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2059=== RUN TestService_RequireScope_OIDC/static_token_may_admin2060=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2061=== RUN TestService_RequireScope_OIDC/static_token_may_write2062=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2063=== RUN TestService_RequireScope_OIDC/reader_may_read2064=== PAUSE TestService_RequireScope_OIDC/reader_may_read2065=== RUN TestService_RequireScope_OIDC/writer_implies_read2066=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2067=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2068=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2069=== CONT TestService_RequireScope_OIDC/builder_may_write2070=== CONT TestService_RequireScope_OIDC/static_token_may_write2071=== CONT TestService_RequireScope_OIDC/static_token_may_admin2072=== CONT TestService_RequireScope_OIDC/reader_may_not_write2073=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2074=== CONT TestService_RequireScope_OIDC/writer_implies_read2075=== CONT TestService_RequireScope_OIDC/reader_may_read2076=== CONT TestService_RequireScope_OIDC/ops_may_not_write2077=== CONT TestService_RequireScope_OIDC/ops_may_admin2078=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2079--- PASS: TestService_RequireScope_OIDC (0.51s)2080 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2081 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2082 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2083 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2084 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2085 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2086 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2087 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2088 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2089 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2090--- PASS: TestCacheStatsHandler (0.46s)2091--- PASS: TestService_ReadScope_PublicByDefault (0.43s)20922026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures2093=== NAME TestClientCADerivations2094 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations299903008/001/store/yj472hxb5mb07zm7if6255vwj6vwjn2m-ca-test2095--- PASS: TestObjectStatsTrigger (0.47s)2096=== NAME TestClientCADerivations2097 client_ca_test.go:139: Found 1 dependencies (including self)2098--- PASS: TestService_ReadAuthMiddleware (0.45s)20992026/09/21 14:12:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21002026/09/21 14:12:16 WARN mTLS auth: bound subjects configured but subject DN unavailable21012026/09/21 14:12:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2102--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.45s)21032026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2104--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)21052026/09/21 14:12:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.754317ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21062026/09/21 14:12:16 INFO Received cleanup request method=DELETE path=/api/pending_closures2107=== NAME TestOrphanedObjectsGC2108 orphaned_objects_gc_test.go:290: GC Test Summary:2109 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2110 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2111 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2112 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2113 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2114--- PASS: TestOrphanedObjectsGC (0.82s)21152026/09/21 14:12:16 INFO Aborted multipart uploads count=12116--- PASS: TestMultipartCleanup (0.57s)2117=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2118=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2119=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2120=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2121=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2122=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2123=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2124=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2125=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2126=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21272026/09/21 14:12:16 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]2128=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2129=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured21302026/09/21 14:12:16 INFO Received uploads request method=POST path=/api/pending_closures21312026/09/21 14:12:16 WARN Authentication failed token_preview=eyJhbGciOi...HyUSAUWRyA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]21322026/09/21 14:12:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21332026/09/21 14:12:16 INFO Uploading yj472hxb5mb07zm7if6255vwj6vwjn2m-ca-test (144B)2134--- PASS: TestService_AuthMiddleware_OIDC (0.47s)2135 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2136 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2137 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2138 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)21392026/09/21 14:12:16 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21402026/09/21 14:12:16 WARN Failed to register uploaded object key=log/gf271v2ph3ssymihp49v6pyks2lq22cz-ca-test.drv error="server returned 404: 404 page not found\n"21412026/09/21 14:12:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21422026/09/21 14:12:16 WARN Failed to register uploaded object key=yj472hxb5mb07zm7if6255vwj6vwjn2m.ls error="server returned 404: 404 page not found\n"21432026/09/21 14:12:16 INFO Signed narinfos id=1 count=121442026/09/21 14:12:16 INFO Uploading 1 narinfos21452026/09/21 14:12:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21462026/09/21 14:12:16 WARN Failed to register uploaded object key=yj472hxb5mb07zm7if6255vwj6vwjn2m.narinfo error="server returned 404: 404 page not found\n"21472026/09/21 14:12:16 INFO Completed upload id=121482026/09/21 14:12:16 INFO Upload complete. (88ms)2149=== NAME TestClientCADerivations2150 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations299903008/001/store/yj472hxb5mb07zm7if6255vwj6vwjn2m-ca-test2151 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2152 Compression: zstd2153 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2154 NarSize: 1442155 References: 2156 Deriver: /build/TestClientCADerivations299903008/001/store/gf271v2ph3ssymihp49v6pyks2lq22cz-ca-test.drv2157 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2158 client_ca_test.go:185: Checking for realisation files in S3...2159 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2160 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21612026/09/21 14:12:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21622026/09/21 14:12:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2163 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2164 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2165 error: binary cache 's3://bucket46?endpoint=http://localhost:38173®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations299903008/001/store'2166 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12167--- PASS: TestClientCADerivations (0.91s)21682026/09/21 14:12:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2169--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2170 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2171 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2172 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.78s)21732026/09/21 14:12:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=730.577269ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21742026/09/21 14:12:17 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=021752026/09/21 14:12:17 INFO Vacuumed table table=pending_closures21762026/09/21 14:12:17 INFO Vacuumed table table=pending_objects21772026/09/21 14:12:17 INFO Vacuumed table table=multipart_uploads21782026/09/21 14:12:17 INFO Vacuumed table table=closures21792026/09/21 14:12:17 INFO Vacuumed table table=objects21802026/09/21 14:12:17 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=021812026/09/21 14:12:17 INFO Vacuumed table table=pending_closures21822026/09/21 14:12:17 INFO Vacuumed table table=pending_objects21832026/09/21 14:12:17 INFO Vacuumed table table=multipart_uploads21842026/09/21 14:12:17 INFO Vacuumed table table=closures21852026/09/21 14:12:17 INFO Vacuumed table table=objects21862026/09/21 14:12:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.753342602s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2187=== NAME TestOrphanedObjectsGCStressTest2188 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2189 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21902026/09/21 14:12:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02191=== NAME TestPinProtectsFromGC2192 client_integration_test.go:794: Pin successfully protected closure from garbage collection2193--- PASS: TestPinProtectsFromGC (3.04s)21942026/09/21 14:12:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02195=== NAME TestClientIntegration2196 client_integration_test.go:323: Objects in database after GC:2197 client_integration_test.go:323: Successfully deleted all objects with GC --force2198--- PASS: TestClientIntegration (2.92s)2199=== NAME TestOrphanedObjectsGCStressTest2200 orphaned_objects_gc_test.go:509: Stress test completed successfully:2201 orphaned_objects_gc_test.go:510: - Active objects preserved: 202202 orphaned_objects_gc_test.go:511: - Objects deleted: 2102203 orphaned_objects_gc_test.go:512: - Total GC'd: 2102204--- PASS: TestOrphanedObjectsGCStressTest (2.62s)22052026/09/21 14:12:19 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-config22062026/09/21 14:12:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.971745ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22072026/09/21 14:12:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.986822ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/09/21 14:12:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.082928ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22092026/09/21 14:12:20 WARN Rate limiter enabled after throttle name=s3-test rate=522102026/09/21 14:12:20 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2211=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2212 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102213 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002214--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.04s)22152026/09/21 14:12:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.492538768s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22162026/09/21 14:12:22 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"22172026/09/21 14:12:22 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_closures22182026/09/21 14:12:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.101263ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22192026/09/21 14:12:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.565106ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22202026/09/21 14:12:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=775.420429ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22212026/09/21 14:12:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.660772575s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2222--- PASS: TestClientErrorHandling (0.00s)2223 --- PASS: TestClientErrorHandling/InvalidStorePath (0.50s)2224 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.58s)2225 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.63s)2226PASS22272026-09-21 14:12:26.248 UTC [129] LOG: received smart shutdown request22282026-09-21 14:12:26.251 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122292026-09-21 14:12:26.263 UTC [134] LOG: shutting down22302026-09-21 14:12:26.264 UTC [134] LOG: checkpoint starting: shutdown immediate22312026-09-21 14:12:26.778 UTC [134] LOG: checkpoint complete: wrote 11101 buffers (67.8%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.243 s, sync=0.240 s, total=0.515 s; sync files=18738, longest=0.002 s, average=0.001 s; distance=255740 kB, estimate=255740 kB; lsn=0/11124FF0, redo lsn=0/11124FF022322026-09-21 14:12:26.854 UTC [129] LOG: database system is shut down2233Running OIDC tests...2234=== RUN TestGlobMatch2235=== PAUSE TestGlobMatch2236=== RUN TestAudienceForIssuer2237=== PAUSE TestAudienceForIssuer2238=== RUN TestValidateToken_ValidToken2239=== PAUSE TestValidateToken_ValidToken2240=== RUN TestValidateToken_WrongAudience2241=== PAUSE TestValidateToken_WrongAudience2242=== RUN TestValidateToken_Expired2243=== PAUSE TestValidateToken_Expired2244=== RUN TestValidateToken_BoundClaimsMismatch2245=== PAUSE TestValidateToken_BoundClaimsMismatch2246=== RUN TestValidateToken_BoundSubjectMismatch2247=== PAUSE TestValidateToken_BoundSubjectMismatch2248=== RUN TestValidateToken_MultipleProviders2249=== PAUSE TestValidateToken_MultipleProviders2250=== RUN TestValidateToken_NoMatchingProvider2251=== PAUSE TestValidateToken_NoMatchingProvider2252=== RUN TestValidateToken_KubernetesServiceAccount2253=== PAUSE TestValidateToken_KubernetesServiceAccount2254=== RUN TestNewValidator_KubernetesRequiresCA2255=== PAUSE TestNewValidator_KubernetesRequiresCA2256=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2257=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2258=== RUN TestScopes_LegacyProviderDefaultsToWrite2259=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2260=== RUN TestScopes_Rules2261=== PAUSE TestScopes_Rules2262=== RUN TestScopes_ConfigValidation2263=== PAUSE TestScopes_ConfigValidation2264=== CONT TestGlobMatch2265=== RUN TestGlobMatch/foo_foo2266=== PAUSE TestGlobMatch/foo_foo2267=== CONT TestNewValidator_KubernetesRequiresCA2268=== CONT TestValidateToken_Expired2269=== RUN TestGlobMatch/foo_bar2270=== PAUSE TestGlobMatch/foo_bar2271=== CONT TestValidateToken_MultipleProviders2272=== CONT TestValidateToken_BoundSubjectMismatch2273=== CONT TestValidateToken_BoundClaimsMismatch2274=== CONT TestAudienceForIssuer2275--- PASS: TestAudienceForIssuer (0.00s)2276=== CONT TestValidateToken_WrongAudience2277=== CONT TestScopes_LegacyProviderDefaultsToWrite2278=== CONT TestScopes_ConfigValidation2279=== CONT TestScopes_Rules2280=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2281=== CONT TestValidateToken_KubernetesServiceAccount2282=== CONT TestValidateToken_NoMatchingProvider2283=== CONT TestValidateToken_ValidToken2284=== RUN TestGlobMatch/*_2285=== PAUSE TestGlobMatch/*_2286=== RUN TestGlobMatch/*_anything2287=== PAUSE TestGlobMatch/*_anything2288=== RUN TestGlobMatch/foo*_foo2289=== PAUSE TestGlobMatch/foo*_foo2290=== RUN TestGlobMatch/foo*_foobar2291=== PAUSE TestGlobMatch/foo*_foobar22922026/09/21 14:12:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42269/oidc22932026/09/21 14:12:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37167/oidc22942026/09/21 14:12:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44639/oidc2295=== RUN TestGlobMatch/foo*_bar22962026/09/21 14:12:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46609/oidc22972026/09/21 14:12:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39243/oidc22982026/09/21 14:12:28 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34937/oidc2299--- PASS: TestScopes_ConfigValidation (0.01s)23002026/09/21 14:12:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39933/oidc23012026/09/21 14:12:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36011/oidc23022026/09/21 14:12:28 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40433/oidc2303=== PAUSE TestGlobMatch/foo*_bar2304=== RUN TestGlobMatch/*bar_bar2305=== PAUSE TestGlobMatch/*bar_bar2306=== RUN TestGlobMatch/*bar_foobar2307=== PAUSE TestGlobMatch/*bar_foobar2308=== RUN TestGlobMatch/*bar_foo23092026/09/21 14:12:28 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34071/oidc2310=== PAUSE TestGlobMatch/*bar_foo2311=== RUN TestGlobMatch/foo*bar_foobar2312=== PAUSE TestGlobMatch/foo*bar_foobar2313=== RUN TestGlobMatch/foo*bar_foo123bar2314=== PAUSE TestGlobMatch/foo*bar_foo123bar2315=== RUN TestGlobMatch/foo*bar_foobarbaz2316=== PAUSE TestGlobMatch/foo*bar_foobarbaz2317=== RUN TestGlobMatch/*/*_foo/bar23182026/09/21 14:12:28 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232319=== PAUSE TestGlobMatch/*/*_foo/bar2320=== RUN TestGlobMatch/*/*_foo2321=== PAUSE TestGlobMatch/*/*_foo2322=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2323=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2324=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02325=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02326=== RUN TestGlobMatch/refs/*/main_refs/heads/main2327=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2328=== RUN TestGlobMatch/fo?_foo2329=== PAUSE TestGlobMatch/fo?_foo2330=== RUN TestGlobMatch/fo?_fo2331=== PAUSE TestGlobMatch/fo?_fo2332=== RUN TestGlobMatch/fo?_fooo2333=== PAUSE TestGlobMatch/fo?_fooo2334=== RUN TestGlobMatch/?oo_foo2335=== PAUSE TestGlobMatch/?oo_foo2336=== RUN TestGlobMatch/?oo_boo2337=== PAUSE TestGlobMatch/?oo_boo2338=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2339=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2340=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2341=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2342=== CONT TestGlobMatch/foo_foo2343=== CONT TestGlobMatch/fo?_foo2344=== CONT TestGlobMatch/refs/*/main_refs/heads/main2345=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2346=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2347=== CONT TestGlobMatch/foo*_bar2348=== CONT TestGlobMatch/foo*bar_foobarbaz2349=== CONT TestGlobMatch/*/*_foo/bar2350=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2351=== CONT TestGlobMatch/*_anything2352=== CONT TestGlobMatch/foo*_foobar2353=== CONT TestGlobMatch/*bar_foobar2354=== CONT TestGlobMatch/*/*_foo2355--- PASS: TestValidateToken_WrongAudience (0.01s)2356=== CONT TestGlobMatch/?oo_boo2357--- PASS: TestValidateToken_Expired (0.02s)2358=== CONT TestGlobMatch/*bar_bar2359=== CONT TestGlobMatch/?oo_foo2360=== CONT TestGlobMatch/*_2361=== CONT TestGlobMatch/foo*_foo2362=== CONT TestGlobMatch/foo*bar_foobar2363=== CONT TestGlobMatch/foo*bar_foo123bar2364=== CONT TestGlobMatch/foo_bar2365=== CONT TestGlobMatch/*bar_foo2366=== CONT TestGlobMatch/fo?_fo2367=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02368=== CONT TestGlobMatch/fo?_fooo2369--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2370--- PASS: TestValidateToken_ValidToken (0.01s)2371--- PASS: TestGlobMatch (0.02s)2372 --- PASS: TestGlobMatch/foo_foo (0.00s)2373 --- PASS: TestGlobMatch/fo?_foo (0.00s)2374 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2375 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2376 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2377 --- PASS: TestGlobMatch/foo*_bar (0.00s)2378 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2379 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2380 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2381 --- PASS: TestGlobMatch/*_anything (0.00s)2382 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2383 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2384 --- PASS: TestGlobMatch/*/*_foo (0.00s)2385 --- PASS: TestGlobMatch/?oo_boo (0.00s)2386 --- PASS: TestGlobMatch/fo?_fo (0.00s)2387 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2388 --- PASS: TestGlobMatch/foo_bar (0.00s)2389 --- PASS: TestGlobMatch/*bar_bar (0.00s)2390 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2391 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2392 --- PASS: TestGlobMatch/*bar_foo (0.00s)2393 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2394 --- PASS: TestGlobMatch/?oo_foo (0.00s)2395 --- PASS: TestGlobMatch/*_ (0.00s)2396 --- PASS: TestGlobMatch/foo*_foo (0.00s)2397--- PASS: TestValidateToken_MultipleProviders (0.02s)23982026/09/21 14:12:28 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:427192399--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2400--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2401--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2402--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2403--- PASS: TestScopes_Rules (0.02s)2404--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)24052026/09/21 14:12:28 http: TLS handshake error from 127.0.0.1:40188: remote error: tls: bad certificate2406--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)2407PASS2408Running hook tests...2409=== RUN TestSendPathsEmpty2410=== PAUSE TestSendPathsEmpty2411=== RUN TestQueueEnqueueAndFetch2412=== PAUSE TestQueueEnqueueAndFetch2413=== RUN TestQueueDeduplication2414=== PAUSE TestQueueDeduplication2415=== RUN TestQueueRemove2416=== PAUSE TestQueueRemove2417=== RUN TestQueueFetchBatchLimit2418=== PAUSE TestQueueFetchBatchLimit2419=== RUN TestQueueRetryMovesToBack2420=== PAUSE TestQueueRetryMovesToBack2421=== RUN TestQueueFetchRemoveLifecycle2422=== PAUSE TestQueueFetchRemoveLifecycle2423=== RUN TestQueueConcurrentWriters2424=== PAUSE TestQueueConcurrentWriters2425=== RUN TestQueueRemoveLargeClosure2426=== PAUSE TestQueueRemoveLargeClosure2427=== RUN TestServerClientIntegration2428=== PAUSE TestServerClientIntegration2429=== RUN TestServerQueueError2430=== PAUSE TestServerQueueError2431=== RUN TestGetListenerSocketActivation2432 server_test.go:210: === RUN TestGetListenerSocketActivation2433 --- PASS: TestGetListenerSocketActivation (0.00s)2434 PASS2435 2436--- PASS: TestGetListenerSocketActivation (0.01s)2437=== RUN TestDrainIsolatesPoisonPath2438=== PAUSE TestDrainIsolatesPoisonPath2439=== RUN TestRunNotBlockedByPoisonHead2440=== PAUSE TestRunNotBlockedByPoisonHead2441=== RUN TestDrainGivesUpWhenServerDown2442=== PAUSE TestDrainGivesUpWhenServerDown2443=== RUN TestFailedPathPrunedByLaterClosure2444=== PAUSE TestFailedPathPrunedByLaterClosure2445=== RUN TestWorkerUploadsAndRemoves2446=== PAUSE TestWorkerUploadsAndRemoves2447=== RUN TestWorkerSkipsGCdPaths2448=== PAUSE TestWorkerSkipsGCdPaths2449=== RUN TestWorkerPrunesClosureDeps2450=== PAUSE TestWorkerPrunesClosureDeps2451=== RUN TestDrainTimeout2452=== PAUSE TestDrainTimeout2453=== CONT TestSendPathsEmpty2454=== CONT TestServerQueueError2455=== CONT TestQueueConcurrentWriters2456--- PASS: TestSendPathsEmpty (0.00s)2457=== CONT TestQueueFetchBatchLimit2458=== CONT TestQueueRetryMovesToBack2459=== CONT TestQueueRemove2460=== CONT TestQueueDeduplication24612026/09/21 14:12:28 ERROR Failed to queue paths error="permission denied" count=12462=== CONT TestServerClientIntegration2463=== CONT TestQueueEnqueueAndFetch2464=== CONT TestQueueFetchRemoveLifecycle2465--- PASS: TestServerQueueError (0.00s)2466=== CONT TestWorkerUploadsAndRemoves2467=== CONT TestWorkerPrunesClosureDeps2468=== CONT TestWorkerSkipsGCdPaths2469=== CONT TestDrainTimeout2470=== CONT TestDrainGivesUpWhenServerDown2471=== CONT TestQueueRemoveLargeClosure2472=== CONT TestFailedPathPrunedByLaterClosure2473=== CONT TestRunNotBlockedByPoisonHead2474=== CONT TestDrainIsolatesPoisonPath2475--- PASS: TestServerClientIntegration (0.00s)24762026/09/21 14:12:28 INFO Uploading batch count=224772026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=224782026/09/21 14:12:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2631585532/002/a24792026/09/21 14:12:28 INFO Uploading batch count=124802026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=124812026/09/21 14:12:28 INFO Uploading batch count=22482--- PASS: TestQueueFetchBatchLimit (0.02s)24832026/09/21 14:12:28 INFO Uploading batch count=424842026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=424852026/09/21 14:12:28 INFO Upload queue status pending=224862026/09/21 14:12:28 INFO Uploading batch count=12487--- PASS: TestQueueRetryMovesToBack (0.02s)24882026/09/21 14:12:28 INFO Upload queue status pending=324892026/09/21 14:12:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2631585532/002/b2490--- PASS: TestQueueEnqueueAndFetch (0.02s)24912026/09/21 14:12:28 INFO Upload queue status pending=224922026/09/21 14:12:28 INFO Upload queue status pending=224932026/09/21 14:12:28 INFO Uploading batch count=124942026/09/21 14:12:28 INFO Uploading batch count=124952026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=124962026/09/21 14:12:28 INFO Uploading batch count=224972026/09/21 14:12:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2050255183/002/bbb24982026/09/21 14:12:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2433798054/002/nonexistent24992026/09/21 14:12:28 INFO Uploading batch count=225002026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=225012026/09/21 14:12:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2631585532/002/c25022026/09/21 14:12:28 INFO Uploading batch count=12503--- PASS: TestQueueDeduplication (0.02s)2504--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2505--- PASS: TestQueueRemove (0.02s)25062026/09/21 14:12:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2631585532/002/d25072026/09/21 14:12:28 INFO Uploading batch count=125082026/09/21 14:12:28 INFO Uploading batch count=225092026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=225102026/09/21 14:12:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2631585532/002/e25112026/09/21 14:12:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2631585532/002/f25122026/09/21 14:12:28 INFO Uploading batch count=125132026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=125142026/09/21 14:12:28 INFO Uploading batch count=125152026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=12516--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25172026/09/21 14:12:28 ERROR Drain finished with paths left in queue remaining=1025182026/09/21 14:12:28 INFO Uploading batch count=125192026/09/21 14:12:28 ERROR Upload failed error="upload failed" count=125202026/09/21 14:12:28 ERROR Drain finished with paths left in queue remaining=12521--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2522--- PASS: TestDrainIsolatesPoisonPath (0.03s)2523--- PASS: TestWorkerUploadsAndRemoves (0.04s)2524--- PASS: TestWorkerSkipsGCdPaths (0.04s)2525--- PASS: TestWorkerPrunesClosureDeps (0.04s)2526--- PASS: TestQueueRemoveLargeClosure (0.08s)25272026/09/21 14:12:28 ERROR Upload failed error="context deadline exceeded" count=225282026/09/21 14:12:28 ERROR Drain finished with paths left in queue remaining=42529--- PASS: TestDrainTimeout (0.22s)2530--- PASS: TestQueueConcurrentWriters (0.28s)25312026/09/21 14:12:29 INFO Uploading batch count=125322026/09/21 14:12:29 INFO Uploading batch count=125332026/09/21 14:12:29 INFO Uploading batch count=125342026/09/21 14:12:29 ERROR Upload failed error="upload failed" count=125352026/09/21 14:12:29 INFO Uploading batch count=125362026/09/21 14:12:29 ERROR Upload failed error="upload failed" count=125372026/09/21 14:12:29 INFO Uploading batch count=125382026/09/21 14:12:29 ERROR Upload failed error="upload failed" count=125392026/09/21 14:12:29 INFO Uploading batch count=125402026/09/21 14:12:29 ERROR Upload failed error="upload failed" count=125412026/09/21 14:12:29 ERROR Drain finished with paths left in queue remaining=12542--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2543PASS