niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #158
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== CONT TestDoServerRequestAttachesToken73=== CONT TestScriptTokenEmptyCommand74=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess75--- PASS: TestScriptTokenEmptyCommand (0.00s)76=== CONT TestDumpPathMatchesNix77=== CONT TestEncodeNixBase32WithRealHash78--- PASS: TestEncodeNixBase32WithRealHash (0.00s)79=== CONT TestFileTokenMissing80=== CONT TestScriptTokenScriptFails812026/08/27 11:06:16 WARN Rate limiter enabled after throttle name=server-test rate=582=== CONT TestScriptTokenBadJSON83=== CONT TestScriptTokenEmptyToken84=== CONT TestScriptTokenCachesUntilRefresh85=== CONT TestScriptTokenNoExpiryRerunsEveryCall86=== CONT TestFileTokenEmpty87--- PASS: TestFileTokenMissing (0.00s)88=== CONT TestFileTokenReadsAndCaches89--- PASS: TestFileTokenEmpty (0.01s)90=== CONT TestStaticToken91--- PASS: TestStaticToken (0.00s)92=== CONT TestSetClientTLSErrors93--- PASS: TestFileTokenReadsAndCaches (0.01s)94=== CONT TestSetClientTLSDoesNotMutateDefaultTransport95--- PASS: TestDoServerRequestAttachesToken (0.01s)96=== CONT TestSetClientTLS97--- PASS: TestScriptTokenScriptFails (0.01s)98=== CONT TestShellSplitErrors99--- PASS: TestShellSplitErrors (0.00s)100=== CONT TestShellSplit101--- PASS: TestShellSplit (0.00s)102=== CONT TestDoWithRetry_BodyReplayedViaGetBody1032026/08/27 11:06:16 WARN Rate limiter enabled after throttle name=server-test rate=51042026/08/27 11:06:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:560911052026/08/27 11:06:16 WARN Rate limiter backed off name=server-test rate=51062026/08/27 11:06:16 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56091107--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)108=== CONT TestResolveStorePath109=== RUN TestSetClientTLSErrors/missing_cert_file110=== PAUSE TestSetClientTLSErrors/missing_cert_file111=== RUN TestSetClientTLSErrors/missing_key_file112=== PAUSE TestSetClientTLSErrors/missing_key_file113=== RUN TestSetClientTLSErrors/missing_ca_file114=== PAUSE TestSetClientTLSErrors/missing_ca_file115=== RUN TestSetClientTLSErrors/invalid_ca_file116=== PAUSE TestSetClientTLSErrors/invalid_ca_file117=== CONT TestGetStorePathHash118=== RUN TestGetStorePathHash/valid_store_path119=== PAUSE TestGetStorePathHash/valid_store_path120=== RUN TestGetStorePathHash/basename_without_hyphen_should_error121=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error122=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error123=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error124=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error125=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error126=== CONT TestPathInfoHashCompatibility127=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)128=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)129=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon130=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon131=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI132=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI133=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512134=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512135=== CONT TestPathInfoCACompatibility136=== RUN TestPathInfoCACompatibility/null_ca_field137=== PAUSE TestPathInfoCACompatibility/null_ca_field138=== RUN TestPathInfoCACompatibility/old_string_format_-_text139=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text140=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive141=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive142=== RUN TestPathInfoCACompatibility/new_structured_format_-_text143=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text144=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method145=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method146=== CONT TestRateLimiterFeedback147=== RUN TestRateLimiterFeedback/429_enables_limiter148=== PAUSE TestRateLimiterFeedback/429_enables_limiter149=== RUN TestRateLimiterFeedback/503_enables_limiter150=== PAUSE TestRateLimiterFeedback/503_enables_limiter151=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter152=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter153=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter154=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter155=== CONT TestParsePathInfoJSONMultiplePaths156=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths157=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths159=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths160=== CONT TestDumpPathWriterError161--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)162=== CONT TestEncodeNixBase32163=== RUN TestEncodeNixBase32/test_string_hash164=== PAUSE TestEncodeNixBase32/test_string_hash165=== RUN TestEncodeNixBase32/empty_input166=== PAUSE TestEncodeNixBase32/empty_input167=== CONT TestDumpPathSingleFile168=== RUN TestSetClientTLS/rejects_connection_without_client_cert169=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert170=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA171=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA172=== RUN TestSetClientTLS/preserves_debug_logging_transport173=== PAUSE TestSetClientTLS/preserves_debug_logging_transport174=== CONT TestConvertHashToNix32175=== RUN TestConvertHashToNix32/SRI_format_to_Nix32176=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32177=== RUN TestConvertHashToNix32/already_Nix32_format178=== PAUSE TestConvertHashToNix32/already_Nix32_format179=== RUN TestConvertHashToNix32/invalid_format180=== PAUSE TestConvertHashToNix32/invalid_format181=== CONT TestPartSizeForNAR182=== RUN TestPartSizeForNAR/zero_stays_at_minimum183=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum184=== RUN TestPartSizeForNAR/small_stays_at_minimum185=== PAUSE TestPartSizeForNAR/small_stays_at_minimum186=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum187=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum188=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts189=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts190=== RUN TestPartSizeForNAR/1_TiB191=== PAUSE TestPartSizeForNAR/1_TiB192=== RUN TestPartSizeForNAR/5_TiB_S3_max_object193=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object194=== RUN TestPartSizeForNAR/capped_at_5_GiB195=== PAUSE TestPartSizeForNAR/capped_at_5_GiB196=== CONT TestUploadMultipart_SupersededByPeer197=== RUN TestUploadMultipart_SupersededByPeer/exists198=== PAUSE TestUploadMultipart_SupersededByPeer/exists199=== RUN TestUploadMultipart_SupersededByPeer/missing200=== PAUSE TestUploadMultipart_SupersededByPeer/missing201=== CONT TestFilterOversizedClosures202=== RUN TestFilterOversizedClosures/no_limit_keeps_everything203=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything204=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped205=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped206=== RUN TestFilterOversizedClosures/all_closures_skipped207=== PAUSE TestFilterOversizedClosures/all_closures_skipped208=== CONT TestCaseHackSuffix209--- PASS: TestResolveStorePath (0.00s)210=== CONT TestParsePathInfoJSON211=== RUN TestParsePathInfoJSON/Nix_format212=== PAUSE TestParsePathInfoJSON/Nix_format213=== RUN TestParsePathInfoJSON/Lix_format214=== PAUSE TestParsePathInfoJSON/Lix_format215=== RUN TestParsePathInfoJSON/empty_input216=== PAUSE TestParsePathInfoJSON/empty_input217=== RUN TestParsePathInfoJSON/whitespace_only218=== PAUSE TestParsePathInfoJSON/whitespace_only219=== RUN TestParsePathInfoJSON/invalid_JSON220=== PAUSE TestParsePathInfoJSON/invalid_JSON221=== CONT TestSetClientTLSErrors/missing_cert_file222=== CONT TestSetClientTLSErrors/missing_ca_file223=== CONT TestSetClientTLSErrors/invalid_ca_file224=== CONT TestSetClientTLSErrors/missing_key_file225=== CONT TestGetStorePathHash/valid_store_path226=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error227=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error228=== CONT TestGetStorePathHash/basename_without_hyphen_should_error229--- PASS: TestGetStorePathHash (0.00s)230 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)231 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)232 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)233 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)234=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)235--- PASS: TestSetClientTLSErrors (0.00s)236 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)237 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)238 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)239 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)240=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI241=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512242=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon243--- PASS: TestPathInfoHashCompatibility (0.00s)244 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)245 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)246 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)247 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)248=== CONT TestPathInfoCACompatibility/null_ca_field249=== CONT TestPathInfoCACompatibility/new_structured_format_-_text250=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method251=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive252=== CONT TestPathInfoCACompatibility/old_string_format_-_text253--- PASS: TestPathInfoCACompatibility (0.00s)254 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)255 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)256 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)257 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)258 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)259=== CONT TestRateLimiterFeedback/429_enables_limiter2602026/08/27 11:06:16 WARN Rate limiter enabled after throttle name=server-test rate=52612026/08/27 11:06:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:560942622026/08/27 11:06:16 WARN Rate limiter backed off name=server-test rate=5263=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths264=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter265=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter266--- PASS: TestScriptTokenBadJSON (0.02s)267=== CONT TestRateLimiterFeedback/503_enables_limiter268=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths269--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)271 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)272=== CONT TestEncodeNixBase32/test_string_hash273=== CONT TestEncodeNixBase32/empty_input274--- PASS: TestEncodeNixBase32 (0.00s)275 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)276 --- PASS: TestEncodeNixBase32/empty_input (0.00s)277=== CONT TestSetClientTLS/rejects_connection_without_client_cert2782026/08/27 11:06:16 WARN Rate limiter enabled after throttle name=server-test rate=52792026/08/27 11:06:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:56100280--- PASS: TestScriptTokenEmptyToken (0.02s)281=== CONT TestConvertHashToNix32/SRI_format_to_Nix322822026/08/27 11:06:16 WARN Rate limiter backed off name=server-test rate=5283=== CONT TestSetClientTLS/preserves_debug_logging_transport284--- PASS: TestRateLimiterFeedback (0.00s)285 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)286 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)287 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)288 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)289=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA290=== CONT TestConvertHashToNix32/invalid_format291=== CONT TestConvertHashToNix32/already_Nix32_format292--- PASS: TestConvertHashToNix32 (0.00s)293 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)294 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)295 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)296=== CONT TestPartSizeForNAR/zero_stays_at_minimum297=== CONT TestPartSizeForNAR/capped_at_5_GiB298=== CONT TestPartSizeForNAR/5_TiB_S3_max_object299=== CONT TestUploadMultipart_SupersededByPeer/exists300=== CONT TestPartSizeForNAR/1_TiB301=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts302=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum303=== CONT TestPartSizeForNAR/small_stays_at_minimum304--- PASS: TestPartSizeForNAR (0.00s)305 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)306 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)307 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)308 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)309 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)310 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)311 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)312=== CONT TestUploadMultipart_SupersededByPeer/missing313=== CONT TestFilterOversizedClosures/no_limit_keeps_everything314--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)315 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)316 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)317=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped318=== CONT TestFilterOversizedClosures/all_closures_skipped3192026/08/27 11:06:16 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=2000320=== CONT TestParsePathInfoJSON/Nix_format3212026/08/27 11:06:16 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=50322--- PASS: TestFilterOversizedClosures (0.00s)323 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)324 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)325 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)326=== CONT TestParsePathInfoJSON/whitespace_only327=== CONT TestParsePathInfoJSON/invalid_JSON328=== CONT TestParsePathInfoJSON/empty_input329=== CONT TestParsePathInfoJSON/Lix_format330--- PASS: TestParsePathInfoJSON (0.00s)331 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)332 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)333 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)334 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)335 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3362026/08/27 11:06:16 http: TLS handshake error from 127.0.0.1:56102: remote error: tls: bad certificate337--- PASS: TestSetClientTLS (0.00s)338 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)339 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)341--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)342--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)343--- PASS: TestDumpPathWriterError (0.04s)344--- PASS: TestDumpPathSingleFile (0.05s)345--- PASS: TestCaseHackSuffix (0.05s)346--- PASS: TestDumpPathMatchesNix (0.08s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld1".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /nix/var/nix/builds/nix-66996-4097137941/postgres3033935872/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: 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.372373Success. You can now start the database server using:374375 pg_ctl -D /nix/var/nix/builds/nix-66996-4097137941/postgres3033935872/data -l logfile start376377/nix/var/nix/builds/nix-66996-4097137941/postgres3033935872:5432 - no response3782026-08-27 11:06:18.424 UTC [67080] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit3792026-08-27 11:06:18.424 UTC [67080] LOG: listening on Unix socket "/nix/var/nix/builds/nix-66996-4097137941/postgres3033935872/.s.PGSQL.5432"3802026-08-27 11:06:18.426 UTC [67087] LOG: database system was shut down at 2026-08-27 11:06:18 UTC3812026-08-27 11:06:18.427 UTC [67080] LOG: database system is ready to accept connections382/nix/var/nix/builds/nix-66996-4097137941/postgres3033935872:5432 - accepting connections383=== RUN TestService_AuthMiddleware384=== PAUSE TestService_AuthMiddleware385=== RUN TestService_AuthMiddleware_MTLSProxyHeader386=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader387=== RUN TestService_AuthMiddleware_MTLSBoundSubjects388=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects389=== RUN TestService_ReadAuthMiddleware390=== PAUSE TestService_ReadAuthMiddleware391=== RUN TestService_AuthMiddleware_OIDC392=== PAUSE TestService_AuthMiddleware_OIDC393=== RUN TestService_RequireScope_OIDC394=== PAUSE TestService_RequireScope_OIDC395=== RUN TestService_ReadScope_PublicByDefault396=== PAUSE TestService_ReadScope_PublicByDefault397=== RUN TestCacheConfigHandler398=== PAUSE TestCacheConfigHandler399=== RUN TestCacheStatsHandler400=== PAUSE TestCacheStatsHandler401=== RUN TestClientCADerivations402=== PAUSE TestClientCADerivations403=== RUN TestClientErrorHandling404=== PAUSE TestClientErrorHandling405=== RUN TestClientIntegration406=== PAUSE TestClientIntegration407=== RUN TestClientMultipleUploads408=== PAUSE TestClientMultipleUploads409=== RUN TestClientWithDependencies410=== PAUSE TestClientWithDependencies411=== RUN TestPinProtectsFromGC412=== PAUSE TestPinProtectsFromGC413=== RUN TestResolveDBConnectionString414=== PAUSE TestResolveDBConnectionString415=== RUN TestGCAdvisoryLockBlocksConcurrentRun4162026-08-27 11:06:18.818 UTC [67164] ERROR: relation "goose_db_version" does not exist at character 364172026-08-27 11:06:18.818 UTC [67164] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4182026/08/27 11:06:18 OK 20241026095416_initial_model.sql (3.3ms)4192026/08/27 11:06:18 OK 20251210153512_drop_unused_gin_index.sql (407.71µs)4202026/08/27 11:06:18 OK 20251218171726_add_pins.sql (732.13µs)4212026/08/27 11:06:18 OK 20260628120000_add_object_size_and_stats.sql (859.5µs)4222026/08/27 11:06:18 goose: successfully migrated database to version: 202606281200004232026/08/27 11:06:18 OK 1_commit_pending_closure.sql (891.71µs)4242026/08/27 11:06:18 OK 2_object_stats_trigger.sql (195.63µs)4252026/08/27 11:06:18 goose: up to current file version: 2426--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.23s)427=== RUN TestGCBugBareHashReferences428=== PAUSE TestGCBugBareHashReferences429=== RUN TestGCMetrics430=== PAUSE TestGCMetrics431=== RUN TestGCTaskStore_StartNew432=== PAUSE TestGCTaskStore_StartNew433=== RUN TestGCTaskStore_DeduplicateSameParams434=== PAUSE TestGCTaskStore_DeduplicateSameParams435=== RUN TestGCTaskStore_ConflictDifferentParams436=== PAUSE TestGCTaskStore_ConflictDifferentParams437=== RUN TestGCTaskStore_GetEmpty438=== PAUSE TestGCTaskStore_GetEmpty439=== RUN TestGCTaskStore_GetReturnsLatest440=== PAUSE TestGCTaskStore_GetReturnsLatest441=== RUN TestGCTaskStore_CompletedAllowsNewTask442=== PAUSE TestGCTaskStore_CompletedAllowsNewTask443=== RUN TestGCTaskStore_PhaseUpdates444=== PAUSE TestGCTaskStore_PhaseUpdates445=== RUN TestGCTaskStore_Fail446=== PAUSE TestGCTaskStore_Fail447=== RUN TestGracefulShutdownDrainsInflight448=== PAUSE TestGracefulShutdownDrainsInflight449=== RUN TestService_healthCheckHandler450=== PAUSE TestService_healthCheckHandler451=== RUN TestService_readinessHandler452=== PAUSE TestService_readinessHandler453=== RUN TestGenerateLandingPage454=== PAUSE TestGenerateLandingPage455=== RUN TestCacheConfigHandlerMaxNarSize456=== PAUSE TestCacheConfigHandlerMaxNarSize457=== RUN TestCreatePendingClosureRejectsOversizedNAR458=== PAUSE TestCreatePendingClosureRejectsOversizedNAR459=== RUN TestNARDeduplicationMetadataUploadBug460=== PAUSE TestNARDeduplicationMetadataUploadBug461=== RUN TestMetricsInventory462=== PAUSE TestMetricsInventory463=== RUN TestService_NativeMTLS464=== PAUSE TestService_NativeMTLS465=== RUN TestServerTLSConfig466=== PAUSE TestServerTLSConfig467=== RUN TestMultipartCleanup468=== PAUSE TestMultipartCleanup469=== RUN TestObjectStatsTrigger470=== PAUSE TestObjectStatsTrigger471=== RUN TestOrphanedObjectsGC472=== PAUSE TestOrphanedObjectsGC473=== RUN TestOrphanedObjectsGCStressTest474=== PAUSE TestOrphanedObjectsGCStressTest475=== RUN TestResurrectedObjectNotDeleted476=== PAUSE TestResurrectedObjectNotDeleted477=== RUN TestParseSingleRange478=== PAUSE TestParseSingleRange479=== RUN TestIsValidCachePath480=== PAUSE TestIsValidCachePath481=== RUN TestReadProxyNarinfo482=== PAUSE TestReadProxyNarinfo483=== RUN TestReadProxyNarinfoAlreadyDecompressed484=== PAUSE TestReadProxyNarinfoAlreadyDecompressed485=== RUN TestReadProxyNarStreaming486=== PAUSE TestReadProxyNarStreaming487=== RUN TestReadProxy404488=== PAUSE TestReadProxy404489=== RUN TestReadProxyInvalidPath490=== PAUSE TestReadProxyInvalidPath491=== RUN TestReadProxyHead492=== PAUSE TestReadProxyHead493=== RUN TestReadProxyConditionalGet494=== PAUSE TestReadProxyConditionalGet495=== RUN TestReadProxyRootRedirectsToIndexHTML496=== PAUSE TestReadProxyRootRedirectsToIndexHTML497=== RUN TestReadProxyDisabled498=== PAUSE TestReadProxyDisabled499=== RUN TestReadRedirectNar500=== PAUSE TestReadRedirectNar501=== RUN TestReadRedirectKeepsNarinfoProxied502=== PAUSE TestReadRedirectKeepsNarinfoProxied503=== RUN TestReadProxyRangeRequest504=== PAUSE TestReadProxyRangeRequest505=== RUN TestRedundantMultipartUpload506=== PAUSE TestRedundantMultipartUpload507=== RUN TestCompleteMultipartUpload_ErrorButObjectExists508=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists509=== RUN TestCompletedNarNotReofferedAcrossClosures510=== PAUSE TestCompletedNarNotReofferedAcrossClosures511=== RUN TestPresignedUploadRegisteredBeforeCommit512=== PAUSE TestPresignedUploadRegisteredBeforeCommit513=== RUN TestService_Rustfstest514=== PAUSE TestService_Rustfstest515=== RUN TestParseSize516=== PAUSE TestParseSize517=== RUN TestSkippedUploadsHandler518=== PAUSE TestSkippedUploadsHandler519=== RUN TestSystemdListenerNotActivated520--- PASS: TestSystemdListenerNotActivated (0.00s)521=== RUN TestWatchdogBeatsWhenHealthy522--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)523=== RUN TestWatchdogSkipsWhenUnhealthy5242026/08/27 11:06:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5252026/08/27 11:06:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5262026/08/27 11:06:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5272026/08/27 11:06:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5282026/08/27 11:06:18 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5292026/08/27 11:06:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5302026/08/27 11:06:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5312026/08/27 11:06:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5322026/08/27 11:06:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5332026/08/27 11:06:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"534--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)535=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle536=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle537=== RUN TestProxyWriteTimeout538=== PAUSE TestProxyWriteTimeout539=== RUN TestIsValidUploadKey540=== PAUSE TestIsValidUploadKey541=== RUN TestUploadHandlersRejectInvalidKeys542=== PAUSE TestUploadHandlersRejectInvalidKeys543=== RUN TestUploadHandlersRejectOversizedBody544=== PAUSE TestUploadHandlersRejectOversizedBody545=== RUN TestService_cleanupPendingClosuresHandler546=== PAUSE TestService_cleanupPendingClosuresHandler547=== RUN TestService_createPendingClosureHandler548=== PAUSE TestService_createPendingClosureHandler549=== RUN TestService_verifyS3Integrity550=== PAUSE TestService_verifyS3Integrity551=== RUN TestCompleteMultipartUnregistered552=== PAUSE TestCompleteMultipartUnregistered553=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT554=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT555=== CONT TestService_AuthMiddleware556=== CONT TestMultipartCleanup557=== CONT TestGCTaskStore_StartNew558--- PASS: TestGCTaskStore_StartNew (0.00s)559=== CONT TestServerTLSConfig560=== RUN TestServerTLSConfig/no_client_CA561=== PAUSE TestServerTLSConfig/no_client_CA562=== RUN TestServerTLSConfig/missing_CA_file563=== PAUSE TestServerTLSConfig/missing_CA_file564=== RUN TestServerTLSConfig/not_a_PEM_file565=== PAUSE TestServerTLSConfig/not_a_PEM_file566=== CONT TestServerTLSConfig/no_client_CA567=== CONT TestResolveDBConnectionString568=== CONT TestService_NativeMTLS569=== RUN TestResolveDBConnectionString/flag_wins570=== PAUSE TestResolveDBConnectionString/flag_wins571=== CONT TestReadProxyRangeRequest572=== CONT TestProxyWriteTimeout573=== CONT TestGCMetrics574=== RUN TestResolveDBConnectionString/file_when_flag_empty575=== PAUSE TestResolveDBConnectionString/file_when_flag_empty576=== RUN TestResolveDBConnectionString/missing_file_is_an_error577=== CONT TestGCBugBareHashReferences578=== CONT TestGCTaskStore_Fail579--- PASS: TestGCTaskStore_Fail (0.00s)580=== CONT TestClientWithDependencies581=== RUN TestProxyWriteTimeout/narinfo582=== PAUSE TestProxyWriteTimeout/narinfo583=== RUN TestProxyWriteTimeout/1_GiB_nar584=== PAUSE TestProxyWriteTimeout/1_GiB_nar585=== RUN TestProxyWriteTimeout/10_GiB_nar586=== PAUSE TestProxyWriteTimeout/10_GiB_nar587=== RUN TestProxyWriteTimeout/unknown_size588=== PAUSE TestProxyWriteTimeout/unknown_size589=== CONT TestPinProtectsFromGC590=== CONT TestClientMultipleUploads591=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error592=== RUN TestResolveDBConnectionString/PGHOST_allows_empty593=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty594=== RUN TestResolveDBConnectionString/nothing_configured595=== PAUSE TestResolveDBConnectionString/nothing_configured596=== CONT TestClientIntegration5972026-08-27 11:06:19.303 UTC [67193] ERROR: relation "goose_db_version" does not exist at character 365982026-08-27 11:06:19.303 UTC [67193] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5992026/08/27 11:06:19 OK 20241026095416_initial_model.sql (11.42ms)6002026-08-27 11:06:19.332 UTC [67195] ERROR: relation "goose_db_version" does not exist at character 366012026-08-27 11:06:19.332 UTC [67195] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6022026-08-27 11:06:19.332 UTC [67194] ERROR: relation "goose_db_version" does not exist at character 366032026-08-27 11:06:19.332 UTC [67194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6042026-08-27 11:06:19.333 UTC [67196] ERROR: relation "goose_db_version" does not exist at character 366052026-08-27 11:06:19.333 UTC [67196] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6062026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (3.14ms)6072026/08/27 11:06:19 OK 20251218171726_add_pins.sql (4.52ms)6082026-08-27 11:06:19.338 UTC [67198] ERROR: relation "goose_db_version" does not exist at character 366092026-08-27 11:06:19.338 UTC [67198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6102026-08-27 11:06:19.338 UTC [67199] ERROR: relation "goose_db_version" does not exist at character 366112026-08-27 11:06:19.338 UTC [67199] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6122026-08-27 11:06:19.338 UTC [67197] ERROR: relation "goose_db_version" does not exist at character 366132026-08-27 11:06:19.338 UTC [67197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6142026-08-27 11:06:19.341 UTC [67201] ERROR: relation "goose_db_version" does not exist at character 366152026-08-27 11:06:19.341 UTC [67201] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6162026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)6172026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006182026-08-27 11:06:19.341 UTC [67200] ERROR: relation "goose_db_version" does not exist at character 366192026-08-27 11:06:19.341 UTC [67200] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6202026/08/27 11:06:19 OK 1_commit_pending_closure.sql (1.64ms)6212026-08-27 11:06:19.344 UTC [67202] ERROR: relation "goose_db_version" does not exist at character 366222026-08-27 11:06:19.344 UTC [67202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6232026/08/27 11:06:19 OK 2_object_stats_trigger.sql (845.88µs)6242026/08/27 11:06:19 goose: up to current file version: 26252026/08/27 11:06:19 OK 20241026095416_initial_model.sql (7.37ms)6262026/08/27 11:06:19 OK 20241026095416_initial_model.sql (7.07ms)6272026/08/27 11:06:19 OK 20241026095416_initial_model.sql (9.38ms)6282026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)6292026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)6302026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (42.43ms)6312026/08/27 11:06:19 OK 20251218171726_add_pins.sql (51.29ms)6322026/08/27 11:06:19 OK 20251218171726_add_pins.sql (58.03ms)6332026/08/27 11:06:19 OK 20251218171726_add_pins.sql (17.69ms)6342026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (7.61ms)6352026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006362026/08/27 11:06:19 OK 20241026095416_initial_model.sql (65.95ms)6372026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)6382026/08/27 11:06:19 OK 1_commit_pending_closure.sql (1.61ms)6392026/08/27 11:06:19 OK 2_object_stats_trigger.sql (171.38µs)6402026/08/27 11:06:19 goose: up to current file version: 26412026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (8.43ms)6422026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006432026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (9.03ms)6442026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006452026/08/27 11:06:19 OK 1_commit_pending_closure.sql (1.19ms)6462026/08/27 11:06:19 OK 2_object_stats_trigger.sql (161µs)6472026/08/27 11:06:19 goose: up to current file version: 26482026/08/27 11:06:19 OK 20241026095416_initial_model.sql (79.07ms)6492026/08/27 11:06:19 OK 1_commit_pending_closure.sql (7.18ms)6502026/08/27 11:06:19 OK 2_object_stats_trigger.sql (165µs)6512026/08/27 11:06:19 goose: up to current file version: 26522026/08/27 11:06:19 OK 20241026095416_initial_model.sql (85.46ms)6532026/08/27 11:06:19 OK 20251218171726_add_pins.sql (20.14ms)6542026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (11.64ms)6552026/08/27 11:06:19 OK 20241026095416_initial_model.sql (89.64ms)6562026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (6.16ms)6572026/08/27 11:06:19 OK 20241026095416_initial_model.sql (90.05ms)6582026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (609µs)6592026/08/27 11:06:19 OK 20251218171726_add_pins.sql (1.32ms)6602026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (921.71µs)6612026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (11.11ms)6622026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006632026/08/27 11:06:19 OK 20251218171726_add_pins.sql (5.53ms)6642026/08/27 11:06:19 OK 20251218171726_add_pins.sql (5.39ms)6652026/08/27 11:06:19 OK 20241026095416_initial_model.sql (51.25ms)6662026/08/27 11:06:19 OK 1_commit_pending_closure.sql (1.16ms)6672026/08/27 11:06:19 OK 2_object_stats_trigger.sql (180.29µs)6682026/08/27 11:06:19 goose: up to current file version: 26692026/08/27 11:06:19 OK 20251210153512_drop_unused_gin_index.sql (9.58ms)6702026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (22.88ms)6712026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006722026/08/27 11:06:19 OK 20251218171726_add_pins.sql (22.58ms)6732026/08/27 11:06:19 OK 20251218171726_add_pins.sql (8.42ms)6742026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (18.23ms)6752026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006762026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (18.34ms)6772026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006782026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (1.07ms)6792026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006802026/08/27 11:06:19 OK 1_commit_pending_closure.sql (1.12ms)6812026/08/27 11:06:19 OK 1_commit_pending_closure.sql (1.44ms)6822026/08/27 11:06:19 OK 1_commit_pending_closure.sql (1.73ms)6832026/08/27 11:06:19 OK 2_object_stats_trigger.sql (325.71µs)6842026/08/27 11:06:19 goose: up to current file version: 26852026/08/27 11:06:19 OK 2_object_stats_trigger.sql (288.88µs)6862026/08/27 11:06:19 goose: up to current file version: 26872026/08/27 11:06:19 OK 2_object_stats_trigger.sql (342.04µs)6882026/08/27 11:06:19 goose: up to current file version: 26892026/08/27 11:06:19 OK 1_commit_pending_closure.sql (7.48ms)6902026/08/27 11:06:19 OK 2_object_stats_trigger.sql (165.83µs)6912026/08/27 11:06:19 goose: up to current file version: 26922026/08/27 11:06:19 OK 20260628120000_add_object_size_and_stats.sql (21.65ms)6932026/08/27 11:06:19 goose: successfully migrated database to version: 202606281200006942026/08/27 11:06:19 OK 1_commit_pending_closure.sql (6.4ms)6952026/08/27 11:06:19 OK 2_object_stats_trigger.sql (193.88µs)6962026/08/27 11:06:19 goose: up to current file version: 2697--- PASS: TestReadProxyRangeRequest (0.40s)698=== CONT TestClientErrorHandling699=== RUN TestClientErrorHandling/InvalidStorePath700=== PAUSE TestClientErrorHandling/InvalidStorePath701=== RUN TestClientErrorHandling/InvalidAuthToken702=== PAUSE TestClientErrorHandling/InvalidAuthToken703=== RUN TestClientErrorHandling/ServerNotAvailable704=== PAUSE TestClientErrorHandling/ServerNotAvailable705=== CONT TestClientCADerivations7062026/08/27 11:06:19 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7072026/08/27 11:06:19 WARN mTLS auth: subject not in bound subjects subject="CN=reader"708--- PASS: TestService_NativeMTLS (0.46s)709=== CONT TestCacheStatsHandler7102026/08/27 11:06:19 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"711--- PASS: TestService_AuthMiddleware (0.58s)712=== CONT TestCacheConfigHandler713=== RUN TestCacheConfigHandler/full_config,_no_issuer714=== PAUSE TestCacheConfigHandler/full_config,_no_issuer715=== RUN TestCacheConfigHandler/no_cache_url_configured716=== PAUSE TestCacheConfigHandler/no_cache_url_configured717=== RUN TestCacheConfigHandler/no_signing_keys718=== PAUSE TestCacheConfigHandler/no_signing_keys719=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator720=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator721=== CONT TestService_ReadScope_PublicByDefault7222026/08/27 11:06:19 INFO Received uploads request method=POST path=/api/pending_closures7232026/08/27 11:06:19 INFO Received cleanup request method=DELETE path=/api/pending_closures7242026/08/27 11:06:19 INFO Aborted multipart uploads count=1725--- PASS: TestMultipartCleanup (0.86s)726=== CONT TestService_RequireScope_OIDC7272026/08/27 11:06:19 INFO OIDC provider initialized name=test728=== NAME TestPinProtectsFromGC729 client_integration_test.go:647: Pinned store path: /nix/var/nix/builds/nix-66996-4097137941/TestPinProtectsFromGC47445935/001/store/2ax7lw17ss2qxaic63a4arjv9nv2hcxy-pinned-file.txt730 client_integration_test.go:648: Unpinned store path: /nix/var/nix/builds/nix-66996-4097137941/TestPinProtectsFromGC47445935/001/store/qgbblfra0rpqqn5h77b5a56hrjkz89cr-unpinned-file.txt731=== NAME TestClientIntegration732 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-66996-4097137941/TestClientIntegration1059577237/002/store/xd8wx7cgsqi5r1zaw8x5j6br4svw4rsf-test-file.txt7332026/08/27 11:06:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"7342026/08/27 11:06:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"7352026/08/27 11:06:20 INFO Received uploads request method=POST path=/api/pending_closures7362026/08/27 11:06:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)7372026/08/27 11:06:20 INFO Uploading 2ax7lw17ss2qxaic63a4arjv9nv2hcxy-pinned-file.txt (128B)7382026/08/27 11:06:20 INFO Received uploads request method=POST path=/api/pending_closures7392026/08/27 11:06:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)7402026/08/27 11:06:20 INFO Uploading xd8wx7cgsqi5r1zaw8x5j6br4svw4rsf-test-file.txt (152B)7412026/08/27 11:06:20 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"742--- PASS: TestGCBugBareHashReferences (1.32s)743=== CONT TestService_AuthMiddleware_OIDC7442026/08/27 11:06:20 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"7452026/08/27 11:06:20 WARN Failed to register uploaded object key=2ax7lw17ss2qxaic63a4arjv9nv2hcxy.ls error="server returned 404: 404 page not found\n"7462026/08/27 11:06:20 INFO OIDC provider initialized name=test7472026/08/27 11:06:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign7482026/08/27 11:06:20 INFO Signed narinfos id=1 count=17492026/08/27 11:06:20 INFO Uploading 1 narinfos7502026/08/27 11:06:20 WARN Failed to register uploaded object key=2ax7lw17ss2qxaic63a4arjv9nv2hcxy.narinfo error="server returned 404: 404 page not found\n"7512026/08/27 11:06:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7522026/08/27 11:06:20 WARN Failed to register uploaded object key=xd8wx7cgsqi5r1zaw8x5j6br4svw4rsf.ls error="server returned 404: 404 page not found\n"7532026/08/27 11:06:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign7542026/08/27 11:06:20 INFO Signed narinfos id=1 count=17552026/08/27 11:06:20 INFO Uploading 1 narinfos7562026/08/27 11:06:20 INFO Completed upload id=17572026/08/27 11:06:20 INFO Upload complete. (265ms)7582026/08/27 11:06:20 WARN Failed to register uploaded object key=xd8wx7cgsqi5r1zaw8x5j6br4svw4rsf.narinfo error="server returned 404: 404 page not found\n"7592026/08/27 11:06:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7602026/08/27 11:06:20 INFO Completed upload id=17612026/08/27 11:06:20 INFO Upload complete. (280ms)762=== NAME TestClientIntegration763 client_integration_test.go:293: Retrieved narinfo from S3:764 StorePath: /nix/var/nix/builds/nix-66996-4097137941/TestClientIntegration1059577237/002/store/xd8wx7cgsqi5r1zaw8x5j6br4svw4rsf-test-file.txt765 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst766 Compression: zstd767 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1768 NarSize: 152769 References: 770 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1771 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)772 client_integration_test.go:294: Decompressed .ls content (64 bytes):773 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}774 client_integration_test.go:297: Testing garbage collection...7752026/08/27 11:06:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures7762026/08/27 11:06:20 INFO Garbage collection started7772026/08/27 11:06:20 INFO Aborted multipart uploads count=07782026/08/27 11:06:20 WARN Force mode enabled - objects will be deleted immediately without grace period7792026/08/27 11:06:20 INFO Aborted multipart uploads count=07802026/08/27 11:06:20 WARN Force mode enabled - objects will be deleted immediately without grace period7812026/08/27 11:06:20 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=07822026/08/27 11:06:20 INFO Vacuumed table table=pending_closures7832026/08/27 11:06:20 INFO Vacuumed table table=pending_objects7842026/08/27 11:06:20 INFO Vacuumed table table=multipart_uploads7852026/08/27 11:06:20 INFO Vacuumed table table=closures7862026/08/27 11:06:20 INFO Vacuumed table table=objects787--- PASS: TestGCMetrics (1.48s)788=== CONT TestService_ReadAuthMiddleware7892026/08/27 11:06:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"7902026-08-27 11:06:20.621 UTC [67250] ERROR: relation "goose_db_version" does not exist at character 367912026-08-27 11:06:20.621 UTC [67250] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026/08/27 11:06:20 INFO Received uploads request method=POST path=/api/pending_closures793=== NAME TestClientMultipleUploads794 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-66996-4097137941/TestClientMultipleUploads511833749/001/store/ym1gglmhn6dn4k1rycj59akwrmxjmbnx-test-file-0.txt7952026/08/27 11:06:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)7962026/08/27 11:06:20 INFO Uploading qgbblfra0rpqqn5h77b5a56hrjkz89cr-unpinned-file.txt (128B)7972026-08-27 11:06:20.635 UTC [67252] ERROR: relation "goose_db_version" does not exist at character 367982026-08-27 11:06:20.635 UTC [67252] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026/08/27 11:06:20 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"8002026-08-27 11:06:20.649 UTC [67254] ERROR: relation "goose_db_version" does not exist at character 368012026-08-27 11:06:20.649 UTC [67254] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026/08/27 11:06:20 WARN Failed to register uploaded object key=qgbblfra0rpqqn5h77b5a56hrjkz89cr.ls error="server returned 404: 404 page not found\n"8032026/08/27 11:06:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8042026/08/27 11:06:20 INFO Signed narinfos id=2 count=18052026/08/27 11:06:20 INFO Uploading 1 narinfos8062026/08/27 11:06:20 WARN Failed to register uploaded object key=qgbblfra0rpqqn5h77b5a56hrjkz89cr.narinfo error="server returned 404: 404 page not found\n"8072026/08/27 11:06:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8082026/08/27 11:06:20 INFO Completed upload id=28092026/08/27 11:06:20 INFO Upload complete. (160ms)8102026/08/27 11:06:20 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=0811 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-66996-4097137941/TestClientMultipleUploads511833749/001/store/90jh1kjxs71xr0wg9yf97m91c9a4y42x-test-file-1.txt8122026/08/27 11:06:20 INFO Vacuumed table table=pending_closures8132026/08/27 11:06:20 INFO Received create pin request method=POST path=/api/pins/myapp8142026/08/27 11:06:20 OK 20241026095416_initial_model.sql (90.91ms)8152026/08/27 11:06:20 OK 20251210153512_drop_unused_gin_index.sql (605.25µs)816=== NAME TestClientWithDependencies817 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-66996-4097137941/TestClientWithDependencies55068572/001/store/gl78wpgfza9lywnfp2pq1qb9yffs21qq-test-script8182026/08/27 11:06:20 OK 20251218171726_add_pins.sql (10.77ms)8192026/08/27 11:06:20 INFO Vacuumed table table=pending_objects8202026/08/27 11:06:20 INFO Vacuumed table table=multipart_uploads8212026/08/27 11:06:20 INFO Vacuumed table table=closures8222026/08/27 11:06:20 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-66996-4097137941/TestPinProtectsFromGC47445935/001/store/2ax7lw17ss2qxaic63a4arjv9nv2hcxy-pinned-file.txt narinfo_key=2ax7lw17ss2qxaic63a4arjv9nv2hcxy.narinfo8232026/08/27 11:06:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures8242026/08/27 11:06:20 INFO Garbage collection started8252026/08/27 11:06:20 INFO Aborted multipart uploads count=08262026/08/27 11:06:20 WARN Force mode enabled - objects will be deleted immediately without grace period8272026/08/27 11:06:20 OK 20260628120000_add_object_size_and_stats.sql (39.81ms)8282026/08/27 11:06:20 goose: successfully migrated database to version: 202606281200008292026/08/27 11:06:20 INFO Vacuumed table table=objects830 client_integration_test.go:596: Found 1 dependencies (including self)831=== NAME TestClientMultipleUploads832 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-66996-4097137941/TestClientMultipleUploads511833749/001/store/51sf4a9hnwj5k0q2y6wm8hsjydniz40f-test-file-2.txt8332026/08/27 11:06:20 OK 1_commit_pending_closure.sql (2.36ms)8342026/08/27 11:06:20 OK 2_object_stats_trigger.sql (1.4ms)8352026/08/27 11:06:20 goose: up to current file version: 28362026/08/27 11:06:20 OK 20241026095416_initial_model.sql (132.49ms)8372026/08/27 11:06:20 OK 20241026095416_initial_model.sql (102.42ms)8382026/08/27 11:06:20 OK 20251210153512_drop_unused_gin_index.sql (9.33ms)8392026/08/27 11:06:20 OK 20251210153512_drop_unused_gin_index.sql (11.21ms)8402026/08/27 11:06:20 OK 20251218171726_add_pins.sql (37.71ms)8412026/08/27 11:06:20 OK 20251218171726_add_pins.sql (37.76ms)8422026/08/27 11:06:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8432026/08/27 11:06:20 INFO Received uploads request method=POST path=/api/pending_closures8442026/08/27 11:06:20 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8452026/08/27 11:06:20 OK 20260628120000_add_object_size_and_stats.sql (8.04ms)8462026/08/27 11:06:20 goose: successfully migrated database to version: 202606281200008472026/08/27 11:06:20 OK 1_commit_pending_closure.sql (7.85ms)8482026/08/27 11:06:20 OK 2_object_stats_trigger.sql (534.88µs)8492026/08/27 11:06:20 goose: up to current file version: 28502026/08/27 11:06:20 OK 20260628120000_add_object_size_and_stats.sql (24.33ms)8512026/08/27 11:06:20 goose: successfully migrated database to version: 202606281200008522026/08/27 11:06:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8532026/08/27 11:06:20 INFO Uploading gl78wpgfza9lywnfp2pq1qb9yffs21qq-test-script (136B)8542026/08/27 11:06:20 OK 1_commit_pending_closure.sql (11.36ms)8552026/08/27 11:06:20 OK 2_object_stats_trigger.sql (253.54µs)8562026/08/27 11:06:20 goose: up to current file version: 28572026/08/27 11:06:20 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=08582026/08/27 11:06:20 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"8592026/08/27 11:06:20 WARN Failed to register uploaded object key=log/63mk62safvbs5mfwgdwwyimi7vcfz5kb-test-script.drv error="server returned 404: 404 page not found\n"8602026/08/27 11:06:20 INFO Received uploads request method=POST path=/api/pending_closures8612026/08/27 11:06:20 WARN Failed to register uploaded object key=gl78wpgfza9lywnfp2pq1qb9yffs21qq.ls error="server returned 404: 404 page not found\n"8622026/08/27 11:06:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8632026/08/27 11:06:20 INFO Signed narinfos id=1 count=18642026/08/27 11:06:20 INFO Uploading 1 narinfos8652026/08/27 11:06:20 INFO Vacuumed table table=pending_closures8662026/08/27 11:06:20 INFO Received uploads request method=POST path=/api/pending_closures8672026/08/27 11:06:20 INFO Received uploads request method=POST path=/api/pending_closures8682026/08/27 11:06:20 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)8692026/08/27 11:06:20 INFO Uploading ym1gglmhn6dn4k1rycj59akwrmxjmbnx-test-file-0.txt (160B)8702026/08/27 11:06:20 INFO Uploading 51sf4a9hnwj5k0q2y6wm8hsjydniz40f-test-file-2.txt (160B)8712026/08/27 11:06:20 INFO Uploading 90jh1kjxs71xr0wg9yf97m91c9a4y42x-test-file-1.txt (160B)8722026/08/27 11:06:21 WARN Failed to register uploaded object key=gl78wpgfza9lywnfp2pq1qb9yffs21qq.narinfo error="server returned 404: 404 page not found\n"8732026/08/27 11:06:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8742026/08/27 11:06:21 INFO Vacuumed table table=pending_objects8752026/08/27 11:06:21 INFO Vacuumed table table=multipart_uploads8762026/08/27 11:06:21 INFO Completed upload id=18772026/08/27 11:06:21 INFO Upload complete. (244ms)8782026/08/27 11:06:21 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"8792026/08/27 11:06:21 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"880=== NAME TestClientWithDependencies881 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-66996-4097137941/TestClientWithDependencies55068572/001/store) requires matching store prefix8822026/08/27 11:06:21 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"8832026/08/27 11:06:21 INFO Vacuumed table table=closures8842026/08/27 11:06:21 INFO Vacuumed table table=objects8852026/08/27 11:06:21 WARN Failed to register uploaded object key=ym1gglmhn6dn4k1rycj59akwrmxjmbnx.ls error="server returned 404: 404 page not found\n"8862026/08/27 11:06:21 WARN Failed to register uploaded object key=51sf4a9hnwj5k0q2y6wm8hsjydniz40f.ls error="server returned 404: 404 page not found\n"8872026/08/27 11:06:21 WARN Failed to register uploaded object key=90jh1kjxs71xr0wg9yf97m91c9a4y42x.ls error="server returned 404: 404 page not found\n"8882026/08/27 11:06:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8892026/08/27 11:06:21 INFO Signed narinfos id=1 count=18902026/08/27 11:06:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8912026/08/27 11:06:21 INFO Signed narinfos id=2 count=18922026/08/27 11:06:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign8932026/08/27 11:06:21 INFO Signed narinfos id=3 count=18942026/08/27 11:06:21 INFO Uploading 3 narinfos8952026/08/27 11:06:21 WARN Failed to register uploaded object key=ym1gglmhn6dn4k1rycj59akwrmxjmbnx.narinfo error="server returned 404: 404 page not found\n"896--- PASS: TestCacheStatsHandler (1.58s)897=== CONT TestService_AuthMiddleware_MTLSBoundSubjects8982026/08/27 11:06:21 WARN Failed to register uploaded object key=51sf4a9hnwj5k0q2y6wm8hsjydniz40f.narinfo error="server returned 404: 404 page not found\n"8992026/08/27 11:06:21 WARN Failed to register uploaded object key=90jh1kjxs71xr0wg9yf97m91c9a4y42x.narinfo error="server returned 404: 404 page not found\n"9002026/08/27 11:06:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9012026/08/27 11:06:21 INFO Completed upload id=1902--- PASS: TestClientWithDependencies (2.07s)903=== CONT TestService_AuthMiddleware_MTLSProxyHeader9042026/08/27 11:06:21 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9052026/08/27 11:06:21 INFO Completed upload id=29062026/08/27 11:06:21 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete9072026/08/27 11:06:21 INFO Completed upload id=39082026/08/27 11:06:21 INFO Upload complete. (361ms)909=== NAME TestClientMultipleUploads910 client_integration_test.go:350: Uploaded 3 paths in 394.9075ms911--- PASS: TestClientMultipleUploads (2.12s)912=== CONT TestCompleteMultipartUnregistered9132026-08-27 11:06:21.234 UTC [67282] ERROR: relation "goose_db_version" does not exist at character 369142026-08-27 11:06:21.234 UTC [67282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC915--- PASS: TestService_ReadScope_PublicByDefault (1.56s)916=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9172026/08/27 11:06:21 OK 20241026095416_initial_model.sql (32.65ms)9182026/08/27 11:06:21 OK 20251210153512_drop_unused_gin_index.sql (9.96ms)9192026/08/27 11:06:21 OK 20251218171726_add_pins.sql (6.19ms)9202026/08/27 11:06:21 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)9212026/08/27 11:06:21 goose: successfully migrated database to version: 202606281200009222026/08/27 11:06:21 OK 1_commit_pending_closure.sql (1.35ms)9232026/08/27 11:06:21 OK 2_object_stats_trigger.sql (373.96µs)9242026/08/27 11:06:21 goose: up to current file version: 29252026-08-27 11:06:21.330 UTC [67290] ERROR: relation "goose_db_version" does not exist at character 369262026-08-27 11:06:21.330 UTC [67290] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026-08-27 11:06:21.330 UTC [67289] ERROR: relation "goose_db_version" does not exist at character 369282026-08-27 11:06:21.330 UTC [67289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC929=== RUN TestService_RequireScope_OIDC/builder_may_write930=== PAUSE TestService_RequireScope_OIDC/builder_may_write931=== RUN TestService_RequireScope_OIDC/builder_may_not_admin932=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin933=== RUN TestService_RequireScope_OIDC/ops_may_admin934=== PAUSE TestService_RequireScope_OIDC/ops_may_admin935=== RUN TestService_RequireScope_OIDC/ops_may_not_write936=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write937=== RUN TestService_RequireScope_OIDC/reader_may_not_write938=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write939=== RUN TestService_RequireScope_OIDC/static_token_may_admin940=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin941=== RUN TestService_RequireScope_OIDC/static_token_may_write942=== PAUSE TestService_RequireScope_OIDC/static_token_may_write943=== RUN TestService_RequireScope_OIDC/reader_may_read944=== PAUSE TestService_RequireScope_OIDC/reader_may_read945=== RUN TestService_RequireScope_OIDC/writer_implies_read946=== PAUSE TestService_RequireScope_OIDC/writer_implies_read947=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read948=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read949=== CONT TestReadProxyNarStreaming950=== NAME TestClientCADerivations951 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-66996-4097137941/TestClientCADerivations3762381550/001/store/bp0683ny5cin9qh41kpf688dny5jdhms-ca-test9522026/08/27 11:06:21 OK 20241026095416_initial_model.sql (65.31ms)9532026/08/27 11:06:21 OK 20241026095416_initial_model.sql (65.74ms)9542026/08/27 11:06:21 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)9552026/08/27 11:06:21 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)9562026/08/27 11:06:21 OK 20251218171726_add_pins.sql (1.8ms)9572026/08/27 11:06:21 OK 20251218171726_add_pins.sql (1.82ms)9582026/08/27 11:06:21 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)9592026/08/27 11:06:21 goose: successfully migrated database to version: 202606281200009602026/08/27 11:06:21 OK 20260628120000_add_object_size_and_stats.sql (3.27ms)9612026/08/27 11:06:21 goose: successfully migrated database to version: 202606281200009622026/08/27 11:06:21 OK 1_commit_pending_closure.sql (1.13ms)9632026/08/27 11:06:21 OK 1_commit_pending_closure.sql (929.5µs)9642026/08/27 11:06:21 OK 2_object_stats_trigger.sql (265.21µs)9652026/08/27 11:06:21 goose: up to current file version: 29662026/08/27 11:06:21 OK 2_object_stats_trigger.sql (372.08µs)9672026/08/27 11:06:21 goose: up to current file version: 2968 client_ca_test.go:139: Found 1 dependencies (including self)969=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token970=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token971=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected972=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected973=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected974=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected975=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured976=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured977=== CONT TestReadRedirectKeepsNarinfoProxied9782026/08/27 11:06:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9792026/08/27 11:06:21 INFO Received uploads request method=POST path=/api/pending_closures980--- PASS: TestService_ReadAuthMiddleware (1.06s)981=== CONT TestReadRedirectNar9822026/08/27 11:06:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9832026/08/27 11:06:21 INFO Uploading bp0683ny5cin9qh41kpf688dny5jdhms-ca-test (144B)9842026/08/27 11:06:21 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9852026/08/27 11:06:21 WARN Failed to register uploaded object key=log/1i32fz22w8n19j8cvkqzzzchfyr2l9jk-ca-test.drv error="server returned 404: 404 page not found\n"9862026/08/27 11:06:21 WARN Failed to register uploaded object key=bp0683ny5cin9qh41kpf688dny5jdhms.ls error="server returned 404: 404 page not found\n"9872026/08/27 11:06:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9882026/08/27 11:06:21 INFO Signed narinfos id=1 count=19892026/08/27 11:06:21 INFO Uploading 1 narinfos9902026/08/27 11:06:21 WARN Failed to register uploaded object key=bp0683ny5cin9qh41kpf688dny5jdhms.narinfo error="server returned 404: 404 page not found\n"9912026/08/27 11:06:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9922026/08/27 11:06:21 INFO Completed upload id=19932026/08/27 11:06:21 INFO Upload complete. (255ms)994=== NAME TestClientCADerivations995 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-66996-4097137941/TestClientCADerivations3762381550/001/store/bp0683ny5cin9qh41kpf688dny5jdhms-ca-test996 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst997 Compression: zstd998 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n999 NarSize: 1441000 References: 1001 Deriver: /nix/var/nix/builds/nix-66996-4097137941/TestClientCADerivations3762381550/001/store/1i32fz22w8n19j8cvkqzzzchfyr2l9jk-ca-test.drv1002 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1003 client_ca_test.go:185: Checking for realisation files in S3...1004 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1005 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1006 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket12?endpoint=http://localhost:56113®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-66996-4097137941/TestClientCADerivations3762381550/001/store'1007 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11008--- PASS: TestClientCADerivations (2.34s)1009=== CONT TestReadProxyDisabled10102026-08-27 11:06:21.874 UTC [67314] ERROR: relation "goose_db_version" does not exist at character 3610112026-08-27 11:06:21.874 UTC [67314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10122026-08-27 11:06:21.874 UTC [67315] ERROR: relation "goose_db_version" does not exist at character 3610132026-08-27 11:06:21.874 UTC [67315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10142026-08-27 11:06:21.892 UTC [67317] ERROR: relation "goose_db_version" does not exist at character 3610152026-08-27 11:06:21.892 UTC [67317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10162026/08/27 11:06:21 OK 20241026095416_initial_model.sql (28.4ms)10172026/08/27 11:06:21 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)10182026/08/27 11:06:21 OK 20251218171726_add_pins.sql (33.3ms)10192026/08/27 11:06:21 OK 20241026095416_initial_model.sql (65.36ms)10202026/08/27 11:06:21 OK 20251210153512_drop_unused_gin_index.sql (826.5µs)10212026/08/27 11:06:21 OK 20260628120000_add_object_size_and_stats.sql (24.35ms)10222026/08/27 11:06:21 goose: successfully migrated database to version: 2026062812000010232026/08/27 11:06:21 OK 1_commit_pending_closure.sql (1.1ms)10242026/08/27 11:06:21 OK 2_object_stats_trigger.sql (235.63µs)10252026/08/27 11:06:21 goose: up to current file version: 210262026/08/27 11:06:21 OK 20251218171726_add_pins.sql (29.16ms)10272026/08/27 11:06:22 OK 20260628120000_add_object_size_and_stats.sql (28.45ms)10282026/08/27 11:06:22 goose: successfully migrated database to version: 2026062812000010292026/08/27 11:06:22 OK 1_commit_pending_closure.sql (1.2ms)10302026/08/27 11:06:22 OK 2_object_stats_trigger.sql (234.29µs)10312026/08/27 11:06:22 goose: up to current file version: 210322026/08/27 11:06:22 OK 20241026095416_initial_model.sql (129.8ms)10332026/08/27 11:06:22 OK 20251210153512_drop_unused_gin_index.sql (6.3ms)10342026/08/27 11:06:22 OK 20251218171726_add_pins.sql (20.85ms)10352026/08/27 11:06:22 OK 20260628120000_add_object_size_and_stats.sql (28.1ms)10362026/08/27 11:06:22 goose: successfully migrated database to version: 202606281200001037--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.93s)1038=== CONT TestReadProxyRootRedirectsToIndexHTML10392026/08/27 11:06:22 OK 1_commit_pending_closure.sql (5.99ms)10402026/08/27 11:06:22 OK 2_object_stats_trigger.sql (945.21µs)10412026/08/27 11:06:22 goose: up to current file version: 210422026/08/27 11:06:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10432026/08/27 11:06:22 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1044--- PASS: TestCompleteMultipartUnregistered (1.03s)1045=== CONT TestReadProxyConditionalGet10462026/08/27 11:06:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"10472026/08/27 11:06:22 WARN mTLS auth: bound subjects configured but subject DN unavailable10482026/08/27 11:06:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1049--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.25s)1050=== CONT TestReadProxyHead10512026-08-27 11:06:22.390 UTC [67327] ERROR: relation "goose_db_version" does not exist at character 3610522026-08-27 11:06:22.390 UTC [67327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10532026-08-27 11:06:22.419 UTC [67330] ERROR: relation "goose_db_version" does not exist at character 3610542026-08-27 11:06:22.419 UTC [67330] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10552026/08/27 11:06:22 OK 20241026095416_initial_model.sql (20.21ms)10562026/08/27 11:06:22 OK 20251210153512_drop_unused_gin_index.sql (381.25µs)10572026/08/27 11:06:22 OK 20251218171726_add_pins.sql (804.88µs)10582026/08/27 11:06:22 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)10592026/08/27 11:06:22 goose: successfully migrated database to version: 2026062812000010602026/08/27 11:06:22 OK 1_commit_pending_closure.sql (1.13ms)10612026/08/27 11:06:22 OK 2_object_stats_trigger.sql (255.46µs)10622026/08/27 11:06:22 goose: up to current file version: 210632026/08/27 11:06:22 OK 20241026095416_initial_model.sql (8.7ms)10642026/08/27 11:06:22 OK 20251210153512_drop_unused_gin_index.sql (715.25µs)10652026/08/27 11:06:22 OK 20251218171726_add_pins.sql (29.67ms)10662026/08/27 11:06:22 OK 20260628120000_add_object_size_and_stats.sql (22.58ms)10672026/08/27 11:06:22 goose: successfully migrated database to version: 2026062812000010682026/08/27 11:06:22 OK 1_commit_pending_closure.sql (9.1ms)10692026/08/27 11:06:22 OK 2_object_stats_trigger.sql (241.83µs)10702026/08/27 11:06:22 goose: up to current file version: 210712026/08/27 11:06:22 INFO Received uploads request method=POST path=/api/pending_closures10722026/08/27 11:06:22 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01073=== NAME TestClientIntegration1074 client_integration_test.go:304: Objects in database after GC:1075 client_integration_test.go:304: Successfully deleted all objects with GC --force1076--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.40s)1077=== CONT TestReadProxyInvalidPath1078--- PASS: TestClientIntegration (3.55s)1079=== CONT TestReadProxy40410802026/08/27 11:06:22 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01081=== NAME TestPinProtectsFromGC1082 client_integration_test.go:710: Pin successfully protected closure from garbage collection1083--- PASS: TestReadProxyNarStreaming (1.39s)1084=== CONT TestParseSingleRange1085=== RUN TestParseSingleRange/none1086=== PAUSE TestParseSingleRange/none1087=== RUN TestParseSingleRange/unknown_unit1088=== PAUSE TestParseSingleRange/unknown_unit1089=== RUN TestParseSingleRange/multi-range_ignored1090=== PAUSE TestParseSingleRange/multi-range_ignored1091=== RUN TestParseSingleRange/malformed_no_dash1092=== PAUSE TestParseSingleRange/malformed_no_dash1093=== RUN TestParseSingleRange/malformed_both_empty1094=== PAUSE TestParseSingleRange/malformed_both_empty1095=== RUN TestParseSingleRange/malformed_end_before_start1096=== PAUSE TestParseSingleRange/malformed_end_before_start1097=== RUN TestParseSingleRange/closed1098=== PAUSE TestParseSingleRange/closed1099=== RUN TestParseSingleRange/open-ended1100=== PAUSE TestParseSingleRange/open-ended1101=== RUN TestParseSingleRange/end_clamped_to_size1102=== PAUSE TestParseSingleRange/end_clamped_to_size1103=== RUN TestParseSingleRange/suffix1104=== PAUSE TestParseSingleRange/suffix1105=== RUN TestParseSingleRange/suffix_exceeds_size1106=== PAUSE TestParseSingleRange/suffix_exceeds_size1107=== RUN TestParseSingleRange/single_byte1108=== PAUSE TestParseSingleRange/single_byte1109=== RUN TestParseSingleRange/start_past_EOF1110=== PAUSE TestParseSingleRange/start_past_EOF1111=== RUN TestParseSingleRange/start_far_past_EOF1112=== PAUSE TestParseSingleRange/start_far_past_EOF1113=== CONT TestGCTaskStore_PhaseUpdates1114--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1115=== CONT TestReadProxyNarinfoAlreadyDecompressed1116--- PASS: TestPinProtectsFromGC (3.74s)1117=== CONT TestReadProxyNarinfo11182026-08-27 11:06:22.864 UTC [67352] ERROR: relation "goose_db_version" does not exist at character 3611192026-08-27 11:06:22.864 UTC [67352] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11202026-08-27 11:06:22.916 UTC [67354] ERROR: relation "goose_db_version" does not exist at character 3611212026-08-27 11:06:22.916 UTC [67354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/08/27 11:06:23 OK 20241026095416_initial_model.sql (86.42ms)11232026/08/27 11:06:23 OK 20251210153512_drop_unused_gin_index.sql (9.37ms)11242026/08/27 11:06:23 OK 20251218171726_add_pins.sql (21.66ms)11252026/08/27 11:06:23 OK 20260628120000_add_object_size_and_stats.sql (31.16ms)11262026/08/27 11:06:23 goose: successfully migrated database to version: 2026062812000011272026/08/27 11:06:23 OK 20241026095416_initial_model.sql (107.94ms)11282026/08/27 11:06:23 OK 1_commit_pending_closure.sql (7.45ms)11292026/08/27 11:06:23 OK 2_object_stats_trigger.sql (3.64ms)11302026/08/27 11:06:23 goose: up to current file version: 211312026/08/27 11:06:23 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)11322026/08/27 11:06:23 OK 20251218171726_add_pins.sql (28.1ms)11332026/08/27 11:06:23 OK 20260628120000_add_object_size_and_stats.sql (27.65ms)11342026/08/27 11:06:23 goose: successfully migrated database to version: 2026062812000011352026/08/27 11:06:23 OK 1_commit_pending_closure.sql (17.5ms)11362026/08/27 11:06:23 OK 2_object_stats_trigger.sql (821.96µs)11372026/08/27 11:06:23 goose: up to current file version: 211382026-08-27 11:06:23.186 UTC [67357] ERROR: relation "goose_db_version" does not exist at character 3611392026-08-27 11:06:23.186 UTC [67357] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1140--- PASS: TestReadRedirectKeepsNarinfoProxied (1.76s)1141=== CONT TestIsValidCachePath1142=== RUN TestIsValidCachePath/narinfo1143=== PAUSE TestIsValidCachePath/narinfo1144=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1145=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1146=== RUN TestIsValidCachePath/nar_zst1147=== PAUSE TestIsValidCachePath/nar_zst1148=== RUN TestIsValidCachePath/nar_xz1149=== PAUSE TestIsValidCachePath/nar_xz1150=== RUN TestIsValidCachePath/nar_bz21151=== PAUSE TestIsValidCachePath/nar_bz21152=== RUN TestIsValidCachePath/nar_uncompressed1153=== PAUSE TestIsValidCachePath/nar_uncompressed1154=== RUN TestIsValidCachePath/ls1155=== PAUSE TestIsValidCachePath/ls1156=== RUN TestIsValidCachePath/log1157=== PAUSE TestIsValidCachePath/log1158=== RUN TestIsValidCachePath/realisation1159=== PAUSE TestIsValidCachePath/realisation1160=== RUN TestIsValidCachePath/nix-cache-info1161=== PAUSE TestIsValidCachePath/nix-cache-info1162=== RUN TestIsValidCachePath/index.html1163=== PAUSE TestIsValidCachePath/index.html1164=== RUN TestIsValidCachePath/traversal_parent1165=== PAUSE TestIsValidCachePath/traversal_parent1166=== RUN TestIsValidCachePath/traversal_in_middle1167=== PAUSE TestIsValidCachePath/traversal_in_middle1168=== RUN TestIsValidCachePath/invalid_char_e1169=== PAUSE TestIsValidCachePath/invalid_char_e1170=== RUN TestIsValidCachePath/invalid_char_u1171=== PAUSE TestIsValidCachePath/invalid_char_u1172=== RUN TestIsValidCachePath/random_path1173=== PAUSE TestIsValidCachePath/random_path1174=== RUN TestIsValidCachePath/empty1175=== PAUSE TestIsValidCachePath/empty1176=== RUN TestIsValidCachePath/leading_slash1177=== PAUSE TestIsValidCachePath/leading_slash1178=== RUN TestIsValidCachePath/wrong_extension1179=== PAUSE TestIsValidCachePath/wrong_extension1180=== RUN TestIsValidCachePath/short_hash1181=== PAUSE TestIsValidCachePath/short_hash1182=== CONT TestGCTaskStore_CompletedAllowsNewTask1183--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1184=== CONT TestGCTaskStore_GetReturnsLatest1185--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1186=== CONT TestOrphanedObjectsGCStressTest11872026/08/27 11:06:23 OK 20241026095416_initial_model.sql (123.53ms)11882026/08/27 11:06:23 OK 20251210153512_drop_unused_gin_index.sql (7.04ms)1189--- PASS: TestReadRedirectNar (1.78s)1190=== CONT TestGCTaskStore_GetEmpty1191--- PASS: TestGCTaskStore_GetEmpty (0.00s)1192=== CONT TestGCTaskStore_ConflictDifferentParams1193--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1194=== CONT TestGCTaskStore_DeduplicateSameParams1195--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1196=== CONT TestResurrectedObjectNotDeleted11972026/08/27 11:06:23 OK 20251218171726_add_pins.sql (28.62ms)11982026/08/27 11:06:23 OK 20260628120000_add_object_size_and_stats.sql (10.67ms)11992026/08/27 11:06:23 goose: successfully migrated database to version: 2026062812000012002026/08/27 11:06:23 OK 1_commit_pending_closure.sql (2.69ms)12012026/08/27 11:06:23 OK 2_object_stats_trigger.sql (584.63µs)12022026/08/27 11:06:23 goose: up to current file version: 21203--- PASS: TestReadProxyDisabled (1.78s)1204=== CONT TestServerTLSConfig/not_a_PEM_file1205=== CONT TestServerTLSConfig/missing_CA_file1206--- PASS: TestServerTLSConfig (0.00s)1207 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1208 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1209 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1210=== CONT TestCacheConfigHandlerMaxNarSize1211--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1212=== CONT TestMetricsInventory12132026-08-27 11:06:23.680 UTC [67367] ERROR: relation "goose_db_version" does not exist at character 3612142026-08-27 11:06:23.680 UTC [67367] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12152026-08-27 11:06:23.738 UTC [67369] ERROR: relation "goose_db_version" does not exist at character 3612162026-08-27 11:06:23.738 UTC [67369] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12172026-08-27 11:06:23.788 UTC [67371] ERROR: relation "goose_db_version" does not exist at character 3612182026-08-27 11:06:23.788 UTC [67371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12192026/08/27 11:06:23 OK 20241026095416_initial_model.sql (72.4ms)12202026/08/27 11:06:23 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)12212026/08/27 11:06:23 OK 20251218171726_add_pins.sql (19.57ms)12222026/08/27 11:06:23 OK 20241026095416_initial_model.sql (51.32ms)12232026/08/27 11:06:23 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)12242026/08/27 11:06:23 goose: successfully migrated database to version: 2026062812000012252026/08/27 11:06:23 OK 20251210153512_drop_unused_gin_index.sql (683.04µs)12262026/08/27 11:06:23 OK 1_commit_pending_closure.sql (974.88µs)12272026/08/27 11:06:23 OK 2_object_stats_trigger.sql (260.29µs)12282026/08/27 11:06:23 goose: up to current file version: 212292026/08/27 11:06:23 OK 20251218171726_add_pins.sql (2.67ms)12302026/08/27 11:06:23 OK 20260628120000_add_object_size_and_stats.sql (47.64ms)12312026/08/27 11:06:23 goose: successfully migrated database to version: 2026062812000012322026/08/27 11:06:23 OK 1_commit_pending_closure.sql (1.83ms)12332026/08/27 11:06:23 OK 2_object_stats_trigger.sql (218.5µs)12342026/08/27 11:06:23 goose: up to current file version: 212352026/08/27 11:06:23 OK 20241026095416_initial_model.sql (85.19ms)12362026/08/27 11:06:23 OK 20251210153512_drop_unused_gin_index.sql (16.35ms)12372026/08/27 11:06:23 OK 20251218171726_add_pins.sql (21.32ms)12382026/08/27 11:06:23 OK 20260628120000_add_object_size_and_stats.sql (24.99ms)12392026/08/27 11:06:23 goose: successfully migrated database to version: 2026062812000012402026/08/27 11:06:23 OK 1_commit_pending_closure.sql (1.78ms)12412026/08/27 11:06:23 OK 2_object_stats_trigger.sql (210.29µs)12422026/08/27 11:06:23 goose: up to current file version: 21243--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.93s)1244=== CONT TestNARDeduplicationMetadataUploadBug1245--- PASS: TestReadProxyHead (1.82s)1246=== CONT TestCreatePendingClosureRejectsOversizedNAR12472026/08/27 11:06:24 INFO Received uploads request method=POST path=/api/pending_closures1248--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1249=== CONT TestOrphanedObjectsGC12502026-08-27 11:06:24.277 UTC [67385] ERROR: relation "goose_db_version" does not exist at character 3612512026-08-27 11:06:24.277 UTC [67385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12522026-08-27 11:06:24.277 UTC [67386] ERROR: relation "goose_db_version" does not exist at character 3612532026-08-27 11:06:24.277 UTC [67386] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026-08-27 11:06:24.279 UTC [67384] ERROR: relation "goose_db_version" does not exist at character 3612552026-08-27 11:06:24.279 UTC [67384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1256--- PASS: TestReadProxyConditionalGet (2.09s)1257=== CONT TestService_readinessHandler12582026-08-27 11:06:24.360 UTC [67387] ERROR: relation "goose_db_version" does not exist at character 3612592026-08-27 11:06:24.360 UTC [67387] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12602026/08/27 11:06:24 OK 20241026095416_initial_model.sql (47.58ms)12612026/08/27 11:06:24 OK 20241026095416_initial_model.sql (47.18ms)12622026/08/27 11:06:24 OK 20251210153512_drop_unused_gin_index.sql (5.99ms)12632026/08/27 11:06:24 OK 20251210153512_drop_unused_gin_index.sql (5.06ms)12642026/08/27 11:06:24 OK 20251218171726_add_pins.sql (2.45ms)12652026/08/27 11:06:24 OK 20241026095416_initial_model.sql (55.65ms)12662026/08/27 11:06:24 OK 20251218171726_add_pins.sql (4.21ms)12672026/08/27 11:06:24 OK 20251210153512_drop_unused_gin_index.sql (8.06ms)12682026/08/27 11:06:24 OK 20241026095416_initial_model.sql (48.28ms)12692026/08/27 11:06:24 OK 20251210153512_drop_unused_gin_index.sql (7.97ms)12702026/08/27 11:06:24 OK 20260628120000_add_object_size_and_stats.sql (25.54ms)12712026/08/27 11:06:24 goose: successfully migrated database to version: 2026062812000012722026/08/27 11:06:24 OK 20251218171726_add_pins.sql (18.31ms)12732026/08/27 11:06:24 OK 20260628120000_add_object_size_and_stats.sql (27.52ms)12742026/08/27 11:06:24 goose: successfully migrated database to version: 2026062812000012752026/08/27 11:06:24 OK 1_commit_pending_closure.sql (2.18ms)12762026/08/27 11:06:24 OK 20251218171726_add_pins.sql (2.32ms)12772026/08/27 11:06:24 OK 1_commit_pending_closure.sql (2.13ms)12782026/08/27 11:06:24 OK 2_object_stats_trigger.sql (633.88µs)12792026/08/27 11:06:24 goose: up to current file version: 212802026/08/27 11:06:24 OK 2_object_stats_trigger.sql (630.42µs)12812026/08/27 11:06:24 goose: up to current file version: 212822026/08/27 11:06:24 OK 20260628120000_add_object_size_and_stats.sql (17.19ms)12832026/08/27 11:06:24 goose: successfully migrated database to version: 2026062812000012842026/08/27 11:06:24 OK 1_commit_pending_closure.sql (2.53ms)12852026/08/27 11:06:24 OK 2_object_stats_trigger.sql (206.92µs)12862026/08/27 11:06:24 goose: up to current file version: 212872026/08/27 11:06:24 OK 20260628120000_add_object_size_and_stats.sql (29.92ms)12882026/08/27 11:06:24 goose: successfully migrated database to version: 2026062812000012892026/08/27 11:06:24 OK 1_commit_pending_closure.sql (8.6ms)12902026/08/27 11:06:24 OK 2_object_stats_trigger.sql (195.83µs)12912026/08/27 11:06:24 goose: up to current file version: 21292--- PASS: TestReadProxyInvalidPath (1.94s)1293=== CONT TestGenerateLandingPage1294--- PASS: TestGenerateLandingPage (0.00s)1295=== CONT TestService_healthCheckHandler12962026-08-27 11:06:24.665 UTC [67392] ERROR: relation "goose_db_version" does not exist at character 3612972026-08-27 11:06:24.665 UTC [67392] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1298--- PASS: TestReadProxy404 (2.06s)1299=== CONT TestGracefulShutdownDrainsInflight13002026/08/27 11:06:24 INFO Starting HTTP server address=127.0.0.1:5624413012026/08/27 11:06:24 INFO Shutdown signal received, draining in-flight requests timeout=10s1302--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1303=== CONT TestService_Rustfstest13042026-08-27 11:06:24.800 UTC [67393] ERROR: relation "goose_db_version" does not exist at character 3613052026-08-27 11:06:24.800 UTC [67393] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1306--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.09s)1307=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle13082026/08/27 11:06:24 OK 20241026095416_initial_model.sql (160.35ms)13092026/08/27 11:06:24 OK 20251210153512_drop_unused_gin_index.sql (11.54ms)13102026/08/27 11:06:24 OK 20251218171726_add_pins.sql (18.81ms)13112026/08/27 11:06:24 OK 20260628120000_add_object_size_and_stats.sql (42.12ms)13122026/08/27 11:06:24 goose: successfully migrated database to version: 2026062812000013132026/08/27 11:06:24 OK 1_commit_pending_closure.sql (6.51ms)13142026/08/27 11:06:24 OK 2_object_stats_trigger.sql (236µs)13152026/08/27 11:06:24 goose: up to current file version: 21316--- PASS: TestReadProxyNarinfo (2.17s)1317=== CONT TestSkippedUploadsHandler13182026/08/27 11:06:24 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001319--- PASS: TestSkippedUploadsHandler (0.00s)1320=== CONT TestParseSize1321--- PASS: TestParseSize (0.00s)1322=== CONT TestService_verifyS3Integrity13232026/08/27 11:06:25 OK 20241026095416_initial_model.sql (210.03ms)13242026/08/27 11:06:25 OK 20251210153512_drop_unused_gin_index.sql (7.37ms)13252026/08/27 11:06:25 OK 20251218171726_add_pins.sql (8.3ms)13262026-08-27 11:06:25.103 UTC [67402] ERROR: relation "goose_db_version" does not exist at character 3613272026-08-27 11:06:25.103 UTC [67402] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13282026/08/27 11:06:25 OK 20260628120000_add_object_size_and_stats.sql (16.27ms)13292026/08/27 11:06:25 goose: successfully migrated database to version: 2026062812000013302026/08/27 11:06:25 OK 1_commit_pending_closure.sql (13.99ms)13312026/08/27 11:06:25 OK 2_object_stats_trigger.sql (236.63µs)13322026/08/27 11:06:25 goose: up to current file version: 213332026/08/27 11:06:25 OK 20241026095416_initial_model.sql (117.9ms)13342026/08/27 11:06:25 OK 20251210153512_drop_unused_gin_index.sql (15.78ms)13352026/08/27 11:06:25 OK 20251218171726_add_pins.sql (41.01ms)13362026/08/27 11:06:25 OK 20260628120000_add_object_size_and_stats.sql (47.66ms)13372026/08/27 11:06:25 goose: successfully migrated database to version: 2026062812000013382026/08/27 11:06:25 OK 1_commit_pending_closure.sql (9.67ms)13392026/08/27 11:06:25 OK 2_object_stats_trigger.sql (221.17µs)13402026/08/27 11:06:25 goose: up to current file version: 21341--- PASS: TestResurrectedObjectNotDeleted (2.01s)1342=== CONT TestUploadHandlersRejectOversizedBody1343=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1344=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1345=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1346=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1347=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1348=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1349=== CONT TestService_cleanupPendingClosuresHandler1350--- PASS: TestMetricsInventory (1.97s)1351=== CONT TestObjectStatsTrigger13522026-08-27 11:06:25.600 UTC [67405] ERROR: relation "goose_db_version" does not exist at character 3613532026-08-27 11:06:25.600 UTC [67405] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13542026-08-27 11:06:25.605 UTC [67407] ERROR: relation "goose_db_version" does not exist at character 3613552026-08-27 11:06:25.605 UTC [67407] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026-08-27 11:06:25.653 UTC [67409] ERROR: relation "goose_db_version" does not exist at character 3613572026-08-27 11:06:25.653 UTC [67409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13582026/08/27 11:06:25 OK 20241026095416_initial_model.sql (53.89ms)13592026/08/27 11:06:25 OK 20251210153512_drop_unused_gin_index.sql (575.25µs)13602026/08/27 11:06:25 OK 20241026095416_initial_model.sql (30.37ms)13612026/08/27 11:06:25 OK 20251210153512_drop_unused_gin_index.sql (313.63µs)13622026/08/27 11:06:25 OK 20251218171726_add_pins.sql (2.18ms)13632026/08/27 11:06:25 OK 20251218171726_add_pins.sql (2.93ms)13642026/08/27 11:06:25 OK 20241026095416_initial_model.sql (8.36ms)13652026/08/27 11:06:25 OK 20251210153512_drop_unused_gin_index.sql (307.54µs)13662026/08/27 11:06:25 OK 20251218171726_add_pins.sql (673.38µs)13672026/08/27 11:06:25 OK 20260628120000_add_object_size_and_stats.sql (10.22ms)13682026/08/27 11:06:25 goose: successfully migrated database to version: 2026062812000013692026/08/27 11:06:25 OK 20260628120000_add_object_size_and_stats.sql (22.07ms)13702026/08/27 11:06:25 goose: successfully migrated database to version: 2026062812000013712026/08/27 11:06:25 OK 20260628120000_add_object_size_and_stats.sql (24.23ms)13722026/08/27 11:06:25 goose: successfully migrated database to version: 2026062812000013732026/08/27 11:06:25 OK 1_commit_pending_closure.sql (16.42ms)13742026/08/27 11:06:25 OK 2_object_stats_trigger.sql (333.21µs)13752026/08/27 11:06:25 goose: up to current file version: 213762026/08/27 11:06:25 OK 1_commit_pending_closure.sql (1ms)13772026/08/27 11:06:25 OK 1_commit_pending_closure.sql (1.67ms)13782026/08/27 11:06:25 OK 2_object_stats_trigger.sql (267.58µs)13792026/08/27 11:06:25 goose: up to current file version: 213802026/08/27 11:06:25 OK 2_object_stats_trigger.sql (259.29µs)13812026/08/27 11:06:25 goose: up to current file version: 213822026/08/27 11:06:26 WARN readiness check failed error="closed pool"1383--- PASS: TestService_readinessHandler (1.82s)1384=== CONT TestUploadHandlersRejectInvalidKeys1385=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1386=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1387=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1388=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1389=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1390=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1391=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1392=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1393=== CONT TestIsValidUploadKey1394=== RUN TestIsValidUploadKey/narinfo1395=== PAUSE TestIsValidUploadKey/narinfo1396=== RUN TestIsValidUploadKey/nar_zst1397=== PAUSE TestIsValidUploadKey/nar_zst1398=== RUN TestIsValidUploadKey/nar_xz1399=== PAUSE TestIsValidUploadKey/nar_xz1400=== RUN TestIsValidUploadKey/nar_plain1401=== PAUSE TestIsValidUploadKey/nar_plain1402=== RUN TestIsValidUploadKey/listing1403=== PAUSE TestIsValidUploadKey/listing1404=== RUN TestIsValidUploadKey/build_log1405=== PAUSE TestIsValidUploadKey/build_log1406=== RUN TestIsValidUploadKey/build_log_home-manager_file1407=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1408=== RUN TestIsValidUploadKey/build_log_plus_in_name1409=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1410=== RUN TestIsValidUploadKey/build_log_question_mark1411=== PAUSE TestIsValidUploadKey/build_log_question_mark1412=== RUN TestIsValidUploadKey/build_log_equals1413=== PAUSE TestIsValidUploadKey/build_log_equals1414=== RUN TestIsValidUploadKey/realisation1415=== PAUSE TestIsValidUploadKey/realisation1416=== RUN TestIsValidUploadKey/realisation_plus_in_output1417=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1418=== RUN TestIsValidUploadKey/nix-cache-info1419=== PAUSE TestIsValidUploadKey/nix-cache-info1420=== RUN TestIsValidUploadKey/index.html1421=== PAUSE TestIsValidUploadKey/index.html1422=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1423=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1424=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1425=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1426=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1427=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1428=== RUN TestIsValidUploadKey/traversal1429=== PAUSE TestIsValidUploadKey/traversal1430=== RUN TestIsValidUploadKey/traversal_nar1431=== PAUSE TestIsValidUploadKey/traversal_nar1432=== RUN TestIsValidUploadKey/absolute1433=== PAUSE TestIsValidUploadKey/absolute1434=== RUN TestIsValidUploadKey/empty_key1435=== PAUSE TestIsValidUploadKey/empty_key1436=== RUN TestIsValidUploadKey/unknown_type1437=== PAUSE TestIsValidUploadKey/unknown_type1438=== CONT TestPresignedUploadRegisteredBeforeCommit1439=== NAME TestNARDeduplicationMetadataUploadBug1440 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-66996-4097137941/TestNARDeduplicationMetadataUploadBug3983378175/001/store/cr23lr1h71c7116v07gshppsacd7jwvn-file1.txt14412026/08/27 11:06:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14422026/08/27 11:06:26 INFO Received uploads request method=POST path=/api/pending_closures14432026/08/27 11:06:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14442026/08/27 11:06:26 INFO Uploading cr23lr1h71c7116v07gshppsacd7jwvn-file1.txt (160B)14452026-08-27 11:06:26.397 UTC [67420] ERROR: relation "goose_db_version" does not exist at character 3614462026-08-27 11:06:26.397 UTC [67420] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14472026/08/27 11:06:26 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14482026/08/27 11:06:26 WARN Failed to register uploaded object key=cr23lr1h71c7116v07gshppsacd7jwvn.ls error="server returned 404: 404 page not found\n"14492026/08/27 11:06:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14502026/08/27 11:06:26 INFO Signed narinfos id=1 count=114512026/08/27 11:06:26 INFO Uploading 1 narinfos14522026/08/27 11:06:26 WARN Failed to register uploaded object key=cr23lr1h71c7116v07gshppsacd7jwvn.narinfo error="server returned 404: 404 page not found\n"14532026/08/27 11:06:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14542026/08/27 11:06:26 INFO Completed upload id=114552026/08/27 11:06:26 INFO Upload complete. (323ms)1456 metadata_upload_test.go:54: Retrieved narinfo from S3:1457 StorePath: /nix/var/nix/builds/nix-66996-4097137941/TestNARDeduplicationMetadataUploadBug3983378175/001/store/cr23lr1h71c7116v07gshppsacd7jwvn-file1.txt1458 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1459 Compression: zstd1460 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1461 NarSize: 1601462 References: 1463 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1464 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1465 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1466 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1467 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-66996-4097137941/TestNARDeduplicationMetadataUploadBug3983378175/001/store/5jmv1a0fkhkab0cr53rphmapk7h512nz-file2.txt14682026/08/27 11:06:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14692026/08/27 11:06:26 OK 20241026095416_initial_model.sql (259.58ms)14702026/08/27 11:06:26 OK 20251210153512_drop_unused_gin_index.sql (15ms)14712026/08/27 11:06:26 INFO Received uploads request method=POST path=/api/pending_closures14722026/08/27 11:06:26 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14732026/08/27 11:06:26 OK 20251218171726_add_pins.sql (49.42ms)14742026/08/27 11:06:26 WARN Failed to register uploaded object key=5jmv1a0fkhkab0cr53rphmapk7h512nz.ls error="server returned 404: 404 page not found\n"14752026/08/27 11:06:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14762026/08/27 11:06:26 INFO Signed narinfos id=2 count=114772026/08/27 11:06:26 INFO Uploading 1 narinfos14782026-08-27 11:06:26.842 UTC [67430] ERROR: relation "goose_db_version" does not exist at character 3614792026-08-27 11:06:26.842 UTC [67430] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14802026/08/27 11:06:26 OK 20260628120000_add_object_size_and_stats.sql (56.31ms)14812026/08/27 11:06:26 goose: successfully migrated database to version: 2026062812000014822026/08/27 11:06:26 WARN Failed to register uploaded object key=5jmv1a0fkhkab0cr53rphmapk7h512nz.narinfo error="server returned 404: 404 page not found\n"14832026/08/27 11:06:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14842026/08/27 11:06:26 INFO Completed upload id=214852026/08/27 11:06:26 INFO Upload complete. (193ms)1486 metadata_upload_test.go:76: Retrieved narinfo from S3:1487 StorePath: /nix/var/nix/builds/nix-66996-4097137941/TestNARDeduplicationMetadataUploadBug3983378175/001/store/5jmv1a0fkhkab0cr53rphmapk7h512nz-file2.txt1488 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1489 Compression: zstd1490 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1491 NarSize: 1601492 References: 1493 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14942026/08/27 11:06:26 OK 1_commit_pending_closure.sql (10.19ms)14952026/08/27 11:06:26 OK 2_object_stats_trigger.sql (269.25µs)14962026/08/27 11:06:26 goose: up to current file version: 21497 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1498 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1499 {"version":1,"root":{"type":"regular","size":44}}1500--- PASS: TestNARDeduplicationMetadataUploadBug (3.00s)1501=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1502--- PASS: TestService_healthCheckHandler (2.50s)1503=== CONT TestRedundantMultipartUpload1504=== NAME TestOrphanedObjectsGC1505 orphaned_objects_gc_test.go:290: GC Test Summary:1506 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1507 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1508 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1509 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1510 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1511--- PASS: TestOrphanedObjectsGC (2.89s)1512=== CONT TestCompletedNarNotReofferedAcrossClosures15132026-08-27 11:06:27.099 UTC [67433] ERROR: relation "goose_db_version" does not exist at character 3615142026-08-27 11:06:27.099 UTC [67433] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15152026/08/27 11:06:27 OK 20241026095416_initial_model.sql (216.19ms)15162026/08/27 11:06:27 OK 20251210153512_drop_unused_gin_index.sql (8.63ms)15172026-08-27 11:06:27.159 UTC [67438] ERROR: relation "goose_db_version" does not exist at character 3615182026-08-27 11:06:27.159 UTC [67438] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15192026/08/27 11:06:27 OK 20251218171726_add_pins.sql (9.49ms)15202026/08/27 11:06:27 OK 20260628120000_add_object_size_and_stats.sql (39.92ms)15212026/08/27 11:06:27 goose: successfully migrated database to version: 2026062812000015222026/08/27 11:06:27 OK 1_commit_pending_closure.sql (1.82ms)15232026/08/27 11:06:27 OK 2_object_stats_trigger.sql (331.67µs)15242026/08/27 11:06:27 goose: up to current file version: 215252026/08/27 11:06:27 OK 20241026095416_initial_model.sql (237.7ms)15262026/08/27 11:06:27 OK 20251210153512_drop_unused_gin_index.sql (14.8ms)1527--- PASS: TestService_Rustfstest (2.66s)1528=== CONT TestProxyWriteTimeout/narinfo1529=== CONT TestProxyWriteTimeout/unknown_size1530=== CONT TestProxyWriteTimeout/10_GiB_nar1531=== CONT TestProxyWriteTimeout/1_GiB_nar1532--- PASS: TestProxyWriteTimeout (0.00s)1533 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1534 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1535 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1536 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1537=== CONT TestResolveDBConnectionString/flag_wins1538=== CONT TestResolveDBConnectionString/nothing_configured1539=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1540=== CONT TestResolveDBConnectionString/missing_file_is_an_error1541=== CONT TestResolveDBConnectionString/file_when_flag_empty1542=== CONT TestService_createPendingClosureHandler1543--- PASS: TestResolveDBConnectionString (0.02s)1544 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1545 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1546 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1547 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1548 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)15492026/08/27 11:06:27 OK 20251218171726_add_pins.sql (47.35ms)15502026/08/27 11:06:27 OK 20260628120000_add_object_size_and_stats.sql (41.69ms)15512026/08/27 11:06:27 goose: successfully migrated database to version: 2026062812000015522026/08/27 11:06:27 OK 1_commit_pending_closure.sql (9.58ms)15532026/08/27 11:06:27 OK 2_object_stats_trigger.sql (686.58µs)15542026/08/27 11:06:27 goose: up to current file version: 215552026/08/27 11:06:27 OK 20241026095416_initial_model.sql (232.02ms)15562026/08/27 11:06:27 OK 20251210153512_drop_unused_gin_index.sql (14.72ms)15572026/08/27 11:06:27 OK 20251218171726_add_pins.sql (43.63ms)15582026/08/27 11:06:27 OK 20260628120000_add_object_size_and_stats.sql (24.88ms)15592026/08/27 11:06:27 goose: successfully migrated database to version: 2026062812000015602026/08/27 11:06:27 OK 1_commit_pending_closure.sql (10.45ms)15612026/08/27 11:06:27 OK 2_object_stats_trigger.sql (842.13µs)15622026/08/27 11:06:27 goose: up to current file version: 215632026-08-27 11:06:27.650 UTC [67442] ERROR: relation "goose_db_version" does not exist at character 3615642026-08-27 11:06:27.650 UTC [67442] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15652026/08/27 11:06:27 INFO Received uploads request method=POST path=/api/pending_closures15662026/08/27 11:06:27 INFO Received uploads request method=POST path=/api/pending_closures15672026-08-27 11:06:27.965 UTC [67445] ERROR: relation "goose_db_version" does not exist at character 3615682026-08-27 11:06:27.965 UTC [67445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15692026/08/27 11:06:28 OK 20241026095416_initial_model.sql (291.62ms)15702026/08/27 11:06:28 OK 20251210153512_drop_unused_gin_index.sql (14.82ms)15712026/08/27 11:06:28 OK 20251218171726_add_pins.sql (29ms)15722026/08/27 11:06:28 OK 20260628120000_add_object_size_and_stats.sql (43.41ms)15732026/08/27 11:06:28 goose: successfully migrated database to version: 2026062812000015742026/08/27 11:06:28 OK 1_commit_pending_closure.sql (14.24ms)15752026/08/27 11:06:28 OK 2_object_stats_trigger.sql (1.03ms)15762026/08/27 11:06:28 goose: up to current file version: 215772026/08/27 11:06:28 OK 20241026095416_initial_model.sql (323.8ms)15782026/08/27 11:06:28 INFO Received cleanup request method=DELETE path=/api/pending_closures15792026/08/27 11:06:28 INFO Aborted multipart uploads count=015802026/08/27 11:06:28 INFO Received uploads request method=POST path=/api/pending_closures15812026/08/27 11:06:28 OK 20251210153512_drop_unused_gin_index.sql (19.31ms)15822026/08/27 11:06:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15832026/08/27 11:06:28 OK 20251218171726_add_pins.sql (33.37ms)15842026/08/27 11:06:28 INFO Received cleanup request method=DELETE path=/api/pending_closures15852026/08/27 11:06:28 OK 20260628120000_add_object_size_and_stats.sql (36.05ms)15862026/08/27 11:06:28 goose: successfully migrated database to version: 2026062812000015872026/08/27 11:06:28 INFO Aborted multipart uploads count=115882026/08/27 11:06:28 OK 1_commit_pending_closure.sql (9.36ms)15892026/08/27 11:06:28 OK 2_object_stats_trigger.sql (680.21µs)15902026/08/27 11:06:28 goose: up to current file version: 215912026/08/27 11:06:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15922026-08-27 11:06:28.469 UTC [67442] ERROR: Closure does not exist: id=115932026-08-27 11:06:28.469 UTC [67442] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE15942026-08-27 11:06:28.469 UTC [67442] STATEMENT: -- name: CommitPendingClosure :exec1595 SELECT commit_pending_closure($1::bigint)1596 1597--- PASS: TestService_cleanupPendingClosuresHandler (3.02s)1598=== CONT TestClientErrorHandling/InvalidStorePath1599--- PASS: TestObjectStatsTrigger (3.13s)1600=== CONT TestClientErrorHandling/ServerNotAvailable16012026-08-27 11:06:28.903 UTC [67450] ERROR: relation "goose_db_version" does not exist at character 3616022026-08-27 11:06:28.903 UTC [67450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16032026/08/27 11:06:29 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-config16042026/08/27 11:06:29 OK 20241026095416_initial_model.sql (208.83ms)16052026/08/27 11:06:29 OK 20251210153512_drop_unused_gin_index.sql (13.4ms)16062026/08/27 11:06:29 OK 20251218171726_add_pins.sql (38.15ms)16072026/08/27 11:06:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.883697ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16082026/08/27 11:06:29 OK 20260628120000_add_object_size_and_stats.sql (54.95ms)16092026/08/27 11:06:29 goose: successfully migrated database to version: 2026062812000016102026/08/27 11:06:29 OK 1_commit_pending_closure.sql (7.36ms)16112026/08/27 11:06:29 OK 2_object_stats_trigger.sql (312.42µs)16122026/08/27 11:06:29 goose: up to current file version: 216132026/08/27 11:06:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16142026/08/27 11:06:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.666639ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16152026/08/27 11:06:29 INFO Received uploads request method=POST path=/api/pending_closures16162026/08/27 11:06:29 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MDdjMDIwYWEtMTA3Ny00ZWRkLTlkYzItZjdiODZmNWQzN2YzLmI1ZjkyODc4LTMyYzMtNGY2OS1hMzY5LTc4YzBhYTc3MzQxN3gxNzg3ODI4Nzg3NzM5NDIyMDAw parts=1016172026/08/27 11:06:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16182026/08/27 11:06:29 INFO Completed upload id=116192026/08/27 11:06:29 INFO Received uploads request method=POST path=/api/pending_closures16202026/08/27 11:06:29 INFO Received uploads request method=POST path=/api/pending_closures16212026/08/27 11:06:29 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16222026/08/27 11:06:29 WARN Found objects in DB but missing from S3, will re-upload count=11623--- PASS: TestService_verifyS3Integrity (4.57s)1624=== CONT TestClientErrorHandling/InvalidAuthToken16252026/08/27 11:06:29 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16262026/08/27 11:06:29 INFO Received uploads request method=POST path=/api/pending_closures1627--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.47s)1628=== CONT TestCacheConfigHandler/full_config,_no_issuer1629=== CONT TestCacheConfigHandler/no_signing_keys1630=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1631=== CONT TestCacheConfigHandler/no_cache_url_configured1632--- PASS: TestCacheConfigHandler (0.00s)1633 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1634 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1635 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1636 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1637=== CONT TestService_RequireScope_OIDC/builder_may_write16382026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[write]1639=== CONT TestService_RequireScope_OIDC/static_token_may_admin1640=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1641=== CONT TestService_RequireScope_OIDC/writer_implies_read16422026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[write]1643=== CONT TestService_RequireScope_OIDC/reader_may_read16442026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[read]1645=== CONT TestService_RequireScope_OIDC/static_token_may_write1646=== CONT TestService_RequireScope_OIDC/ops_may_not_write16472026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[admin]1648=== CONT TestService_RequireScope_OIDC/reader_may_not_write16492026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[read]1650=== CONT TestService_RequireScope_OIDC/ops_may_admin16512026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[admin]1652=== CONT TestService_RequireScope_OIDC/builder_may_not_admin16532026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[write]1654=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16552026/08/27 11:06:29 INFO OIDC auth successful provider=test scopes=[write]1656=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16572026/08/27 11:06:29 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]1658=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1659=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16602026/08/27 11:06:29 WARN Authentication failed token_preview=eyJhbGciOi...HLNmLbhvHg token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1661=== CONT TestParseSingleRange/none1662=== CONT TestParseSingleRange/open-ended1663=== CONT TestParseSingleRange/start_far_past_EOF1664=== CONT TestParseSingleRange/start_past_EOF1665=== CONT TestParseSingleRange/single_byte1666=== CONT TestParseSingleRange/suffix_exceeds_size1667=== CONT TestParseSingleRange/suffix1668=== CONT TestParseSingleRange/end_clamped_to_size1669=== CONT TestParseSingleRange/malformed_both_empty1670=== CONT TestParseSingleRange/closed1671=== CONT TestParseSingleRange/malformed_end_before_start1672=== CONT TestParseSingleRange/multi-range_ignored1673=== CONT TestParseSingleRange/malformed_no_dash1674=== CONT TestParseSingleRange/unknown_unit1675--- PASS: TestParseSingleRange (0.00s)1676 --- PASS: TestParseSingleRange/none (0.00s)1677 --- PASS: TestParseSingleRange/open-ended (0.00s)1678 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1679 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1680 --- PASS: TestParseSingleRange/single_byte (0.00s)1681 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1682 --- PASS: TestParseSingleRange/suffix (0.00s)1683 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1684 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1685 --- PASS: TestParseSingleRange/closed (0.00s)1686 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1687 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1688 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1689 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1690=== CONT TestIsValidCachePath/narinfo1691=== CONT TestIsValidCachePath/index.html1692=== CONT TestIsValidCachePath/short_hash1693=== CONT TestIsValidCachePath/wrong_extension1694=== CONT TestIsValidCachePath/leading_slash1695=== CONT TestIsValidCachePath/empty1696=== CONT TestIsValidCachePath/random_path1697=== CONT TestIsValidCachePath/invalid_char_u1698=== CONT TestIsValidCachePath/invalid_char_e1699=== CONT TestIsValidCachePath/traversal_in_middle1700=== CONT TestIsValidCachePath/traversal_parent1701=== CONT TestIsValidCachePath/nar_uncompressed1702=== CONT TestIsValidCachePath/nix-cache-info1703=== CONT TestIsValidCachePath/realisation1704=== CONT TestIsValidCachePath/log1705=== CONT TestIsValidCachePath/ls1706=== CONT TestIsValidCachePath/nar_xz1707=== CONT TestIsValidCachePath/nar_bz21708=== CONT TestIsValidCachePath/nar_zst1709=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1710--- PASS: TestIsValidCachePath (0.00s)1711 --- PASS: TestIsValidCachePath/narinfo (0.00s)1712 --- PASS: TestIsValidCachePath/index.html (0.00s)1713 --- PASS: TestIsValidCachePath/short_hash (0.00s)1714 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1715 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1716 --- PASS: TestIsValidCachePath/empty (0.00s)1717 --- PASS: TestIsValidCachePath/random_path (0.00s)1718 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1719 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1720 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1721 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1722 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1723 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1724 --- PASS: TestIsValidCachePath/realisation (0.00s)1725 --- PASS: TestIsValidCachePath/log (0.00s)1726 --- PASS: TestIsValidCachePath/ls (0.00s)1727 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1728 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1729 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1730 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1731=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17322026/08/27 11:06:29 INFO Received uploads request method=POST path=/1733--- PASS: TestService_RequireScope_OIDC (1.44s)1734 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1735 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1736 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1737 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1738 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1739 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1740 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1741 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1742 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1743 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1744--- PASS: TestService_AuthMiddleware_OIDC (1.11s)1745 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1746 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1747 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1748 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17492026-08-27 11:06:29.701 UTC [67457] ERROR: relation "goose_db_version" does not exist at character 3617502026-08-27 11:06:29.701 UTC [67457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17512026-08-27 11:06:29.732 UTC [67458] ERROR: relation "goose_db_version" does not exist at character 3617522026-08-27 11:06:29.732 UTC [67458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17532026-08-27 11:06:29.733 UTC [67459] ERROR: relation "goose_db_version" does not exist at character 3617542026-08-27 11:06:29.733 UTC [67459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17552026/08/27 11:06:29 OK 20241026095416_initial_model.sql (88.31ms)17562026/08/27 11:06:29 OK 20251210153512_drop_unused_gin_index.sql (12.37ms)17572026-08-27 11:06:29.845 UTC [67460] ERROR: relation "goose_db_version" does not exist at character 3617582026-08-27 11:06:29.845 UTC [67460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17592026/08/27 11:06:29 OK 20251218171726_add_pins.sql (11.59ms)17602026/08/27 11:06:29 OK 20241026095416_initial_model.sql (74.38ms)17612026/08/27 11:06:29 OK 20251210153512_drop_unused_gin_index.sql (7.84ms)17622026/08/27 11:06:29 OK 20260628120000_add_object_size_and_stats.sql (14.46ms)17632026/08/27 11:06:29 goose: successfully migrated database to version: 2026062812000017642026/08/27 11:06:29 OK 20251218171726_add_pins.sql (6.1ms)17652026/08/27 11:06:29 OK 20241026095416_initial_model.sql (94.4ms)17662026/08/27 11:06:29 OK 1_commit_pending_closure.sql (6.45ms)17672026/08/27 11:06:29 OK 2_object_stats_trigger.sql (233.54µs)17682026/08/27 11:06:29 goose: up to current file version: 217692026/08/27 11:06:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=730.512831ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17702026/08/27 11:06:29 OK 20251210153512_drop_unused_gin_index.sql (11.21ms)17712026/08/27 11:06:29 OK 20260628120000_add_object_size_and_stats.sql (36.02ms)17722026/08/27 11:06:29 goose: successfully migrated database to version: 2026062812000017732026/08/27 11:06:29 OK 1_commit_pending_closure.sql (5.08ms)17742026/08/27 11:06:29 OK 2_object_stats_trigger.sql (200.21µs)17752026/08/27 11:06:29 goose: up to current file version: 217762026/08/27 11:06:29 OK 20251218171726_add_pins.sql (34.87ms)1777=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17782026/08/27 11:06:29 INFO Received request for more parts method=POST path=/17792026/08/27 11:06:29 OK 20260628120000_add_object_size_and_stats.sql (37.47ms)17802026/08/27 11:06:29 goose: successfully migrated database to version: 2026062812000017812026/08/27 11:06:29 OK 1_commit_pending_closure.sql (1.02ms)17822026/08/27 11:06:29 OK 2_object_stats_trigger.sql (274µs)17832026/08/27 11:06:29 goose: up to current file version: 21784=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17852026/08/27 11:06:29 INFO Received complete multipart upload request method=POST path=/1786--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1787 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)1788 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1789 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1790=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17912026/08/27 11:06:29 INFO Received uploads request method=POST path=/1792=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17932026/08/27 11:06:29 INFO Received complete multipart upload request method=POST path=/1794=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17952026/08/27 11:06:29 INFO Received request for more parts method=POST path=/1796=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17972026/08/27 11:06:29 INFO Received uploads request method=POST path=/1798--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1799 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1800 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1801 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1802 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1803=== CONT TestIsValidUploadKey/narinfo1804=== CONT TestIsValidUploadKey/realisation_plus_in_output1805=== CONT TestIsValidUploadKey/unknown_type1806=== CONT TestIsValidUploadKey/empty_key1807=== CONT TestIsValidUploadKey/absolute1808=== CONT TestIsValidUploadKey/traversal_nar1809=== CONT TestIsValidUploadKey/traversal1810=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1811=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1812=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1813=== CONT TestIsValidUploadKey/index.html1814=== CONT TestIsValidUploadKey/nix-cache-info1815=== CONT TestIsValidUploadKey/build_log_home-manager_file1816=== CONT TestIsValidUploadKey/realisation1817=== CONT TestIsValidUploadKey/build_log_equals1818=== CONT TestIsValidUploadKey/build_log_question_mark1819=== CONT TestIsValidUploadKey/build_log_plus_in_name1820=== CONT TestIsValidUploadKey/nar_plain1821=== CONT TestIsValidUploadKey/build_log1822=== CONT TestIsValidUploadKey/listing1823=== CONT TestIsValidUploadKey/nar_xz1824=== CONT TestIsValidUploadKey/nar_zst1825--- PASS: TestIsValidUploadKey (0.00s)1826 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1827 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1828 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1829 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1830 --- PASS: TestIsValidUploadKey/absolute (0.00s)1831 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1832 --- PASS: TestIsValidUploadKey/traversal (0.00s)1833 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1834 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1835 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1836 --- PASS: TestIsValidUploadKey/index.html (0.00s)1837 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1838 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1839 --- PASS: TestIsValidUploadKey/realisation (0.00s)1840 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1841 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1842 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1843 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1844 --- PASS: TestIsValidUploadKey/build_log (0.00s)1845 --- PASS: TestIsValidUploadKey/listing (0.00s)1846 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1847 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)18482026/08/27 11:06:30 OK 20241026095416_initial_model.sql (148.73ms)18492026/08/27 11:06:30 INFO Received uploads request method=POST path=/api/pending_closures18502026/08/27 11:06:30 OK 20251210153512_drop_unused_gin_index.sql (6.63ms)18512026/08/27 11:06:30 OK 20251218171726_add_pins.sql (27.43ms)18522026/08/27 11:06:30 OK 20260628120000_add_object_size_and_stats.sql (43.22ms)18532026/08/27 11:06:30 goose: successfully migrated database to version: 2026062812000018542026/08/27 11:06:30 OK 1_commit_pending_closure.sql (6.59ms)18552026/08/27 11:06:30 OK 2_object_stats_trigger.sql (357.17µs)18562026/08/27 11:06:30 goose: up to current file version: 218572026/08/27 11:06:30 INFO Received uploads request method=POST path=/api/pending_closures18582026/08/27 11:06:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18592026/08/27 11:06:30 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDdjMDIwYWEtMTA3Ny00ZWRkLTlkYzItZjdiODZmNWQzN2YzLjBhZDFkZjJmLWMwYTMtNGIzMS05OTZkLTA0NDlmNThhMDAzN3gxNzg3ODI4NzkwMDYxMzkyMDAw18602026/08/27 11:06:30 INFO Received uploads request method=POST path=/api/pending_closures18612026/08/27 11:06:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDdjMDIwYWEtMTA3Ny00ZWRkLTlkYzItZjdiODZmNWQzN2YzLjBhZDFkZjJmLWMwYTMtNGIzMS05OTZkLTA0NDlmNThhMDAzN3gxNzg3ODI4NzkwMDYxMzkyMDAw parts=11862--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.33s)18632026/08/27 11:06:30 INFO Received uploads request method=POST path=/api/pending_closures18642026/08/27 11:06:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.467584741s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18652026/08/27 11:06:30 INFO Received uploads request method=POST path=/api/pending_closures18662026/08/27 11:06:30 INFO Received uploads request method=POST path=/api/pending_closures18672026/08/27 11:06:30 INFO Received uploads request method=POST path=/api/pending_closures18682026-08-27 11:06:30.861 UTC [67461] ERROR: relation "goose_db_version" does not exist at character 3618692026-08-27 11:06:30.861 UTC [67461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18702026/08/27 11:06:31 OK 20241026095416_initial_model.sql (253.63ms)18712026/08/27 11:06:31 OK 20251210153512_drop_unused_gin_index.sql (22.72ms)18722026/08/27 11:06:31 OK 20251218171726_add_pins.sql (42.37ms)18732026/08/27 11:06:31 OK 20260628120000_add_object_size_and_stats.sql (42.62ms)18742026/08/27 11:06:31 goose: successfully migrated database to version: 2026062812000018752026/08/27 11:06:31 OK 1_commit_pending_closure.sql (12.78ms)18762026/08/27 11:06:31 OK 2_object_stats_trigger.sql (504.54µs)18772026/08/27 11:06:31 goose: up to current file version: 218782026-08-27 11:06:31.997 UTC [67464] ERROR: relation "goose_db_version" does not exist at character 3618792026-08-27 11:06:31.997 UTC [67464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18802026/08/27 11:06:32 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"18812026/08/27 11:06:32 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_closures18822026/08/27 11:06:32 OK 20241026095416_initial_model.sql (143.21ms)18832026/08/27 11:06:32 OK 20251210153512_drop_unused_gin_index.sql (15.4ms)18842026/08/27 11:06:32 OK 20251218171726_add_pins.sql (43.24ms)18852026/08/27 11:06:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.622662ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18862026/08/27 11:06:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18872026/08/27 11:06:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18882026/08/27 11:06:32 OK 20260628120000_add_object_size_and_stats.sql (56.6ms)18892026/08/27 11:06:32 goose: successfully migrated database to version: 2026062812000018902026/08/27 11:06:32 OK 1_commit_pending_closure.sql (6.25ms)18912026/08/27 11:06:32 OK 2_object_stats_trigger.sql (440.75µs)18922026/08/27 11:06:32 goose: up to current file version: 218932026/08/27 11:06:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDdjMDIwYWEtMTA3Ny00ZWRkLTlkYzItZjdiODZmNWQzN2YzLmZiMDg3N2M3LTc2NGEtNGYxMC1iYTBkLTM2ZjJmYzdjMDdmMHgxNzg3ODI4NzkwMjUwNzE2MDAw parts=121894--- PASS: TestRedundantMultipartUpload (5.30s)18952026/08/27 11:06:32 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MDdjMDIwYWEtMTA3Ny00ZWRkLTlkYzItZjdiODZmNWQzN2YzLjk1NDdkNjA1LTMwMzctNDcwMi05YmE4LTFiNGM5MWM1M2MxYXgxNzg3ODI4NzkwNjU5NzMwMDAw parts=1018962026/08/27 11:06:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18972026/08/27 11:06:32 INFO Completed upload id=118982026/08/27 11:06:32 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018992026/08/27 11:06:32 INFO Received uploads request method=POST path=/api/pending_closures19002026/08/27 11:06:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures19012026/08/27 11:06:32 INFO Aborted multipart uploads count=019022026/08/27 11:06:32 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=019032026/08/27 11:06:32 INFO Vacuumed table table=pending_closures19042026/08/27 11:06:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19052026/08/27 11:06:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.691706ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19062026/08/27 11:06:32 INFO Vacuumed table table=pending_objects19072026/08/27 11:06:32 INFO Vacuumed table table=multipart_uploads19082026/08/27 11:06:32 INFO Vacuumed table table=closures19092026/08/27 11:06:32 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MDdjMDIwYWEtMTA3Ny00ZWRkLTlkYzItZjdiODZmNWQzN2YzLjBmNzkyZTQxLWMwOTQtNDQ5Yi1iODY0LWU3ZjE1YWY3ZjYwNngxNzg3ODI4NzkwNDY4MjU4MDAw parts=1219102026/08/27 11:06:32 INFO Received uploads request method=POST path=/api/pending_closures1911--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.46s)19122026/08/27 11:06:32 INFO Vacuumed table table=objects19132026/08/27 11:06:32 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001914--- PASS: TestService_createPendingClosureHandler (5.13s)19152026/08/27 11:06:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19162026/08/27 11:06:32 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19172026/08/27 11:06:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=798.733926ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19182026/08/27 11:06:33 WARN Rate limiter enabled after throttle name=s3-test rate=519192026/08/27 11:06:33 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1920=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1921 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101922 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001923--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.24s)1924=== NAME TestOrphanedObjectsGCStressTest1925 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1926 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19272026/08/27 11:06:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.455521839s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1928 orphaned_objects_gc_test.go:509: Stress test completed successfully:1929 orphaned_objects_gc_test.go:510: - Active objects preserved: 201930 orphaned_objects_gc_test.go:511: - Objects deleted: 2101931 orphaned_objects_gc_test.go:512: - Total GC'd: 2101932--- PASS: TestOrphanedObjectsGCStressTest (10.50s)1933--- PASS: TestClientErrorHandling (0.00s)1934 --- PASS: TestClientErrorHandling/InvalidStorePath (3.11s)1935 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.32s)1936 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.45s)1937PASS1938{"timestamp":"2026-08-27T11:06:35.189129Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56296","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1836,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}19392026-08-27 11:06:35.319 UTC [67080] LOG: received smart shutdown request19402026-08-27 11:06:35.320 UTC [67080] LOG: background worker "logical replication launcher" (PID 67090) exited with exit code 119412026-08-27 11:06:35.329 UTC [67085] LOG: shutting down19422026-08-27 11:06:35.329 UTC [67085] LOG: checkpoint starting: shutdown immediate19432026-08-27 11:06:36.422 UTC [67085] LOG: checkpoint complete: wrote 13656 buffers (83.3%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.806 s, sync=0.286 s, total=1.094 s; sync files=16812, longest=0.001 s, average=0.001 s; distance=235561 kB, estimate=235561 kB; lsn=0/FD95490, redo lsn=0/FD9549019442026-08-27 11:06:36.427 UTC [67080] LOG: database system is shut down1945Running OIDC tests...1946=== RUN TestGlobMatch1947=== PAUSE TestGlobMatch1948=== RUN TestAudienceForIssuer1949=== PAUSE TestAudienceForIssuer1950=== RUN TestValidateToken_ValidToken1951=== PAUSE TestValidateToken_ValidToken1952=== RUN TestValidateToken_WrongAudience1953=== PAUSE TestValidateToken_WrongAudience1954=== RUN TestValidateToken_Expired1955=== PAUSE TestValidateToken_Expired1956=== RUN TestValidateToken_BoundClaimsMismatch1957=== PAUSE TestValidateToken_BoundClaimsMismatch1958=== RUN TestValidateToken_BoundSubjectMismatch1959=== PAUSE TestValidateToken_BoundSubjectMismatch1960=== RUN TestValidateToken_MultipleProviders1961=== PAUSE TestValidateToken_MultipleProviders1962=== RUN TestValidateToken_NoMatchingProvider1963=== PAUSE TestValidateToken_NoMatchingProvider1964=== RUN TestValidateToken_KubernetesServiceAccount1965=== PAUSE TestValidateToken_KubernetesServiceAccount1966=== RUN TestNewValidator_KubernetesRequiresCA1967=== PAUSE TestNewValidator_KubernetesRequiresCA1968=== RUN TestScopes_LegacyProviderDefaultsToWrite1969=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1970=== RUN TestScopes_Rules1971=== PAUSE TestScopes_Rules1972=== RUN TestScopes_ConfigValidation1973=== PAUSE TestScopes_ConfigValidation1974=== CONT TestGlobMatch1975=== CONT TestValidateToken_Expired1976=== RUN TestGlobMatch/foo_foo1977=== PAUSE TestGlobMatch/foo_foo1978=== RUN TestGlobMatch/foo_bar1979=== PAUSE TestGlobMatch/foo_bar1980=== RUN TestGlobMatch/*_1981=== PAUSE TestGlobMatch/*_1982=== RUN TestGlobMatch/*_anything1983=== CONT TestValidateToken_MultipleProviders1984=== PAUSE TestGlobMatch/*_anything1985=== RUN TestGlobMatch/foo*_foo1986=== PAUSE TestGlobMatch/foo*_foo1987=== RUN TestGlobMatch/foo*_foobar1988=== CONT TestValidateToken_WrongAudience1989=== PAUSE TestGlobMatch/foo*_foobar1990=== RUN TestGlobMatch/foo*_bar1991=== PAUSE TestGlobMatch/foo*_bar1992=== RUN TestGlobMatch/*bar_bar1993=== PAUSE TestGlobMatch/*bar_bar1994=== RUN TestGlobMatch/*bar_foobar1995=== PAUSE TestGlobMatch/*bar_foobar1996=== RUN TestGlobMatch/*bar_foo1997=== PAUSE TestGlobMatch/*bar_foo1998=== RUN TestGlobMatch/foo*bar_foobar1999=== PAUSE TestGlobMatch/foo*bar_foobar2000=== RUN TestGlobMatch/foo*bar_foo123bar2001=== PAUSE TestGlobMatch/foo*bar_foo123bar2002=== RUN TestGlobMatch/foo*bar_foobarbaz2003=== PAUSE TestGlobMatch/foo*bar_foobarbaz2004=== RUN TestGlobMatch/*/*_foo/bar2005=== PAUSE TestGlobMatch/*/*_foo/bar2006=== RUN TestGlobMatch/*/*_foo2007=== PAUSE TestGlobMatch/*/*_foo2008=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2009=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2010=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02011=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02012=== RUN TestGlobMatch/refs/*/main_refs/heads/main2013=== CONT TestValidateToken_ValidToken2014=== CONT TestAudienceForIssuer2015--- PASS: TestAudienceForIssuer (0.00s)2016=== CONT TestValidateToken_KubernetesServiceAccount2017=== CONT TestValidateToken_BoundClaimsMismatch2018=== CONT TestScopes_LegacyProviderDefaultsToWrite2019=== CONT TestScopes_ConfigValidation2020=== CONT TestScopes_Rules2021=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2022=== RUN TestGlobMatch/fo?_foo2023=== PAUSE TestGlobMatch/fo?_foo2024=== RUN TestGlobMatch/fo?_fo2025=== PAUSE TestGlobMatch/fo?_fo2026=== RUN TestGlobMatch/fo?_fooo2027=== PAUSE TestGlobMatch/fo?_fooo2028=== RUN TestGlobMatch/?oo_foo2029=== PAUSE TestGlobMatch/?oo_foo2030=== RUN TestGlobMatch/?oo_boo2031=== PAUSE TestGlobMatch/?oo_boo2032=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2033=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2034=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2035=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2036=== CONT TestNewValidator_KubernetesRequiresCA20372026/08/27 11:06:37 INFO OIDC provider initialized name=test20382026/08/27 11:06:37 INFO OIDC provider initialized name=test2039--- PASS: TestScopes_ConfigValidation (0.00s)2040=== CONT TestValidateToken_NoMatchingProvider20412026/08/27 11:06:37 INFO OIDC provider initialized name=provider220422026/08/27 11:06:37 INFO OIDC provider initialized name=test20432026/08/27 11:06:37 INFO OIDC provider initialized name=test20442026/08/27 11:06:37 INFO OIDC provider initialized name=test20452026/08/27 11:06:37 INFO OIDC provider initialized name=test20462026/08/27 11:06:37 INFO OIDC provider initialized name=provider120472026/08/27 11:06:37 INFO OIDC provider initialized name=provider12048--- PASS: TestValidateToken_WrongAudience (0.01s)2049=== CONT TestValidateToken_BoundSubjectMismatch2050--- PASS: TestValidateToken_Expired (0.01s)2051=== CONT TestGlobMatch/foo_foo2052=== CONT TestGlobMatch/*/*_foo/bar2053=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2054=== CONT TestGlobMatch/?oo_boo2055=== CONT TestGlobMatch/?oo_foo2056=== CONT TestGlobMatch/fo?_fooo2057=== CONT TestGlobMatch/fo?_fo2058=== CONT TestGlobMatch/fo?_foo2059=== CONT TestGlobMatch/refs/*/main_refs/heads/main2060=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02061=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2062=== CONT TestGlobMatch/*/*_foo2063=== CONT TestGlobMatch/*bar_bar2064=== CONT TestGlobMatch/foo*bar_foobarbaz2065=== CONT TestGlobMatch/foo*bar_foo123bar2066=== CONT TestGlobMatch/foo*bar_foobar2067=== CONT TestGlobMatch/*bar_foo2068=== CONT TestGlobMatch/*bar_foobar2069=== CONT TestGlobMatch/foo*_foo2070=== CONT TestGlobMatch/foo*_bar2071=== CONT TestGlobMatch/foo*_foobar2072=== CONT TestGlobMatch/*_2073=== CONT TestGlobMatch/*_anything2074=== CONT TestGlobMatch/foo_bar2075--- PASS: TestValidateToken_ValidToken (0.01s)2076=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2077--- PASS: TestGlobMatch (0.00s)2078 --- PASS: TestGlobMatch/foo_foo (0.00s)2079 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2080 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2081 --- PASS: TestGlobMatch/?oo_boo (0.00s)2082 --- PASS: TestGlobMatch/?oo_foo (0.00s)2083 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2084 --- PASS: TestGlobMatch/fo?_fo (0.00s)2085 --- PASS: TestGlobMatch/fo?_foo (0.00s)2086 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2087 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2088 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2089 --- PASS: TestGlobMatch/*/*_foo (0.00s)2090 --- PASS: TestGlobMatch/*bar_bar (0.00s)2091 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2092 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2093 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2094 --- PASS: TestGlobMatch/*bar_foo (0.00s)2095 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2096 --- PASS: TestGlobMatch/foo*_foo (0.00s)2097 --- PASS: TestGlobMatch/foo*_bar (0.00s)2098 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2099 --- PASS: TestGlobMatch/*_ (0.00s)2100 --- PASS: TestGlobMatch/*_anything (0.00s)2101 --- PASS: TestGlobMatch/foo_bar (0.00s)2102 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)21032026/08/27 11:06:37 INFO OIDC provider initialized name=kubernetes21042026/08/27 11:06:37 INFO OIDC provider initialized name=test2105--- PASS: TestValidateToken_MultipleProviders (0.01s)2106--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2107--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2108--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2109--- PASS: TestValidateToken_BoundSubjectMismatch (0.00s)21102026/08/27 11:06:37 http: TLS handshake error from 127.0.0.1:56356: remote error: tls: bad certificate2111--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2112--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2113--- PASS: TestScopes_Rules (0.01s)2114PASS2115Running hook tests...2116=== RUN TestSendPathsEmpty2117=== PAUSE TestSendPathsEmpty2118=== RUN TestQueueEnqueueAndFetch2119=== PAUSE TestQueueEnqueueAndFetch2120=== RUN TestQueueDeduplication2121=== PAUSE TestQueueDeduplication2122=== RUN TestQueueRemove2123=== PAUSE TestQueueRemove2124=== RUN TestQueueFetchBatchLimit2125=== PAUSE TestQueueFetchBatchLimit2126=== RUN TestQueueRetryMovesToBack2127=== PAUSE TestQueueRetryMovesToBack2128=== RUN TestQueueFetchRemoveLifecycle2129=== PAUSE TestQueueFetchRemoveLifecycle2130=== RUN TestQueueConcurrentWriters2131=== PAUSE TestQueueConcurrentWriters2132=== RUN TestQueueRemoveLargeClosure2133=== PAUSE TestQueueRemoveLargeClosure2134=== RUN TestServerClientIntegration2135=== PAUSE TestServerClientIntegration2136=== RUN TestServerQueueError2137=== PAUSE TestServerQueueError2138=== RUN TestGetListenerSocketActivation2139 server_test.go:210: === RUN TestGetListenerSocketActivation2140 --- PASS: TestGetListenerSocketActivation (0.00s)2141 PASS2142 2143--- PASS: TestGetListenerSocketActivation (0.01s)2144=== RUN TestDrainIsolatesPoisonPath2145=== PAUSE TestDrainIsolatesPoisonPath2146=== RUN TestRunNotBlockedByPoisonHead2147=== PAUSE TestRunNotBlockedByPoisonHead2148=== RUN TestDrainGivesUpWhenServerDown2149=== PAUSE TestDrainGivesUpWhenServerDown2150=== RUN TestFailedPathPrunedByLaterClosure2151=== PAUSE TestFailedPathPrunedByLaterClosure2152=== RUN TestWorkerUploadsAndRemoves2153=== PAUSE TestWorkerUploadsAndRemoves2154=== RUN TestWorkerSkipsGCdPaths2155=== PAUSE TestWorkerSkipsGCdPaths2156=== RUN TestWorkerPrunesClosureDeps2157=== PAUSE TestWorkerPrunesClosureDeps2158=== RUN TestDrainTimeout2159=== PAUSE TestDrainTimeout2160=== CONT TestSendPathsEmpty2161=== CONT TestServerQueueError2162--- PASS: TestSendPathsEmpty (0.00s)2163=== CONT TestQueueFetchBatchLimit2164=== CONT TestServerClientIntegration2165=== CONT TestWorkerUploadsAndRemoves2166=== CONT TestQueueDeduplication2167=== CONT TestQueueRemove2168=== CONT TestWorkerPrunesClosureDeps2169=== CONT TestQueueConcurrentWriters2170=== CONT TestDrainTimeout2171=== CONT TestQueueRetryMovesToBack21722026/08/27 11:06:37 ERROR Failed to queue paths error="permission denied" count=12173--- PASS: TestServerQueueError (0.00s)2174=== CONT TestQueueRemoveLargeClosure2175--- PASS: TestServerClientIntegration (0.00s)2176=== CONT TestDrainGivesUpWhenServerDown21772026/08/27 11:06:37 INFO Upload queue status pending=221782026/08/27 11:06:37 INFO Uploading batch count=221792026/08/27 11:06:37 INFO Uploading batch count=221802026/08/27 11:06:37 INFO Uploading batch count=221812026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=221822026/08/27 11:06:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66996-4097137941/TestDrainGivesUpWhenServerDown1793505031/002/a2183--- PASS: TestQueueRemove (0.01s)2184=== CONT TestFailedPathPrunedByLaterClosure21852026/08/27 11:06:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66996-4097137941/TestDrainGivesUpWhenServerDown1793505031/002/b21862026/08/27 11:06:37 INFO Uploading batch count=221872026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=22188--- PASS: TestQueueFetchBatchLimit (0.01s)2189=== CONT TestQueueFetchRemoveLifecycle21902026/08/27 11:06:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66996-4097137941/TestDrainGivesUpWhenServerDown1793505031/002/c21912026/08/27 11:06:37 INFO Upload queue status pending=221922026/08/27 11:06:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66996-4097137941/TestDrainGivesUpWhenServerDown1793505031/002/d21932026/08/27 11:06:37 INFO Uploading batch count=12194--- PASS: TestQueueDeduplication (0.01s)2195=== CONT TestRunNotBlockedByPoisonHead2196--- PASS: TestQueueRetryMovesToBack (0.01s)2197=== CONT TestQueueEnqueueAndFetch21982026/08/27 11:06:37 INFO Uploading batch count=221992026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=222002026/08/27 11:06:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66996-4097137941/TestDrainGivesUpWhenServerDown1793505031/002/e22012026/08/27 11:06:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66996-4097137941/TestDrainGivesUpWhenServerDown1793505031/002/f22022026/08/27 11:06:37 ERROR Drain finished with paths left in queue remaining=1022032026/08/27 11:06:37 INFO Upload queue status pending=322042026/08/27 11:06:37 INFO Uploading batch count=122052026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=122062026/08/27 11:06:37 INFO Uploading batch count=122072026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=122082026/08/27 11:06:37 INFO Uploading batch count=122092026/08/27 11:06:37 INFO Uploading batch count=12210--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2211=== CONT TestWorkerSkipsGCdPaths2212--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2213=== CONT TestDrainIsolatesPoisonPath2214--- PASS: TestQueueEnqueueAndFetch (0.00s)2215--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22162026/08/27 11:06:37 INFO Upload queue status pending=222172026/08/27 11:06:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-66996-4097137941/TestWorkerSkipsGCdPaths1647386550/002/nonexistent22182026/08/27 11:06:37 INFO Uploading batch count=422192026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=422202026/08/27 11:06:37 INFO Uploading batch count=122212026/08/27 11:06:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66996-4097137941/TestDrainIsolatesPoisonPath1222853664/002/bbb22222026/08/27 11:06:37 INFO Uploading batch count=122232026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=122242026/08/27 11:06:37 INFO Uploading batch count=122252026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=122262026/08/27 11:06:37 INFO Uploading batch count=122272026/08/27 11:06:37 ERROR Upload failed error="upload failed" count=122282026/08/27 11:06:37 ERROR Drain finished with paths left in queue remaining=12229--- PASS: TestDrainIsolatesPoisonPath (0.00s)2230--- PASS: TestWorkerUploadsAndRemoves (0.03s)2231--- PASS: TestWorkerPrunesClosureDeps (0.03s)2232--- PASS: TestWorkerSkipsGCdPaths (0.02s)2233--- PASS: TestQueueRemoveLargeClosure (0.06s)2234--- PASS: TestQueueConcurrentWriters (0.10s)22352026/08/27 11:06:37 ERROR Upload failed error="context deadline exceeded" count=222362026/08/27 11:06:37 ERROR Drain finished with paths left in queue remaining=42237--- PASS: TestDrainTimeout (0.21s)22382026/08/27 11:06:38 INFO Uploading batch count=122392026/08/27 11:06:38 INFO Uploading batch count=122402026/08/27 11:06:38 INFO Uploading batch count=122412026/08/27 11:06:38 ERROR Upload failed error="upload failed" count=122422026/08/27 11:06:38 INFO Uploading batch count=122432026/08/27 11:06:38 ERROR Upload failed error="upload failed" count=122442026/08/27 11:06:38 INFO Uploading batch count=122452026/08/27 11:06:38 ERROR Upload failed error="upload failed" count=122462026/08/27 11:06:38 INFO Uploading batch count=122472026/08/27 11:06:38 ERROR Upload failed error="upload failed" count=122482026/08/27 11:06:38 ERROR Drain finished with paths left in queue remaining=12249--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2250PASS