niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #194
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathCaseHackMatchesNix13--- PASS: TestDumpPathCaseHackMatchesNix (0.07s)14=== RUN TestDumpPathCaseHackCollision15--- PASS: TestDumpPathCaseHackCollision (0.00s)16=== RUN TestDumpPathMatchesNix17=== PAUSE TestDumpPathMatchesNix18=== RUN TestDumpPathSingleFile19=== PAUSE TestDumpPathSingleFile20=== RUN TestDumpPathWriterError21=== PAUSE TestDumpPathWriterError22=== RUN TestEncodeNixBase3223=== PAUSE TestEncodeNixBase3224=== RUN TestEncodeNixBase32WithRealHash25=== PAUSE TestEncodeNixBase32WithRealHash26=== RUN TestConvertHashToNix3227=== PAUSE TestConvertHashToNix3228=== RUN TestGetStorePathHash29=== PAUSE TestGetStorePathHash30=== RUN TestPathInfoHashCompatibility31=== PAUSE TestPathInfoHashCompatibility32=== RUN TestParsePathInfoJSON33=== PAUSE TestParsePathInfoJSON34=== RUN TestParsePathInfoJSONMultiplePaths35=== PAUSE TestParsePathInfoJSONMultiplePaths36=== RUN TestPathInfoCACompatibility37=== PAUSE TestPathInfoCACompatibility38=== RUN TestRateLimiterFeedback39=== PAUSE TestRateLimiterFeedback40=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess41=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== RUN TestResolveStorePath43=== PAUSE TestResolveStorePath44=== RUN TestDoWithRetry_BodyReplayedViaGetBody45=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody46=== RUN TestShellSplit47=== PAUSE TestShellSplit48=== RUN TestShellSplitErrors49=== PAUSE TestShellSplitErrors50=== RUN TestStreamPushReportsEveryPath51=== PAUSE TestStreamPushReportsEveryPath52=== RUN TestStreamPushBatchesUnderLoad53=== PAUSE TestStreamPushBatchesUnderLoad54=== RUN TestStreamPushIsolatesFailures55=== PAUSE TestStreamPushIsolatesFailures56=== RUN TestStreamPushGivesUpOnDeadServer57=== PAUSE TestStreamPushGivesUpOnDeadServer58=== RUN TestSetClientTLS59=== PAUSE TestSetClientTLS60=== RUN TestSetClientTLSDoesNotMutateDefaultTransport61=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport62=== RUN TestSetClientTLSErrors63=== PAUSE TestSetClientTLSErrors64=== RUN TestStaticToken65=== PAUSE TestStaticToken66=== RUN TestFileTokenReadsAndCaches67=== PAUSE TestFileTokenReadsAndCaches68=== RUN TestFileTokenMissing69=== PAUSE TestFileTokenMissing70=== RUN TestFileTokenEmpty71=== PAUSE TestFileTokenEmpty72=== RUN TestScriptTokenNoExpiryRerunsEveryCall73=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall74=== RUN TestScriptTokenCachesUntilRefresh75=== PAUSE TestScriptTokenCachesUntilRefresh76=== RUN TestScriptTokenEmptyToken77=== PAUSE TestScriptTokenEmptyToken78=== RUN TestScriptTokenBadJSON79=== PAUSE TestScriptTokenBadJSON80=== RUN TestScriptTokenScriptFails81=== PAUSE TestScriptTokenScriptFails82=== RUN TestScriptTokenEmptyCommand83=== PAUSE TestScriptTokenEmptyCommand84=== CONT TestDoServerRequestAttachesToken85=== CONT TestShellSplit86=== CONT TestFileTokenReadsAndCaches87=== CONT TestStreamPushGivesUpOnDeadServer88=== CONT TestConvertHashToNix3289=== CONT TestScriptTokenEmptyToken90=== RUN TestConvertHashToNix32/SRI_format_to_Nix3291--- PASS: TestShellSplit (0.00s)92=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3293=== CONT TestScriptTokenScriptFails94=== RUN TestConvertHashToNix32/already_Nix32_format95=== PAUSE TestConvertHashToNix32/already_Nix32_format96=== RUN TestConvertHashToNix32/invalid_format97=== PAUSE TestConvertHashToNix32/invalid_format98=== CONT TestDumpPathMatchesNix99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestEncodeNixBase32WithRealHash102--- PASS: TestEncodeNixBase32WithRealHash (0.00s)103=== CONT TestEncodeNixBase32104=== RUN TestEncodeNixBase32/test_string_hash105=== PAUSE TestEncodeNixBase32/test_string_hash106=== RUN TestEncodeNixBase32/empty_input107=== PAUSE TestEncodeNixBase32/empty_input108=== CONT TestStreamPushReportsEveryPath109=== CONT TestDumpPathWriterError1102026/09/10 17:37:05 ERROR Upload failed error="connection refused" count=201112026/09/10 17:37:05 ERROR Server seems unavailable, giving up on batch untried=17112=== CONT TestShellSplitErrors113--- PASS: TestShellSplitErrors (0.00s)114=== CONT TestDumpPathSingleFile115=== CONT TestScriptTokenBadJSON116--- PASS: TestFileTokenReadsAndCaches (0.00s)117--- PASS: TestStreamPushReportsEveryPath (0.00s)118=== CONT TestDoWithRetry_BodyReplayedViaGetBody119=== CONT TestPathInfoCACompatibility120=== RUN TestPathInfoCACompatibility/null_ca_field121--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)122=== PAUSE TestPathInfoCACompatibility/null_ca_field123=== CONT TestResolveStorePath124=== RUN TestPathInfoCACompatibility/old_string_format_-_text125--- PASS: TestScriptTokenScriptFails (0.00s)126=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess127=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1282026/09/10 17:37:05 WARN Rate limiter enabled after throttle name=server-test rate=5129=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive130=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive131=== RUN TestPathInfoCACompatibility/new_structured_format_-_text132=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text133=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method134=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method135=== CONT TestRateLimiterFeedback136=== RUN TestRateLimiterFeedback/429_enables_limiter137=== PAUSE TestRateLimiterFeedback/429_enables_limiter138=== RUN TestRateLimiterFeedback/503_enables_limiter139=== PAUSE TestRateLimiterFeedback/503_enables_limiter140=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter141=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter142=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter143=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter144--- PASS: TestResolveStorePath (0.00s)145=== CONT TestScriptTokenNoExpiryRerunsEveryCall146=== CONT TestScriptTokenCachesUntilRefresh1472026/09/10 17:37:05 WARN Rate limiter enabled after throttle name=server-test rate=51482026/09/10 17:37:05 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49921149--- PASS: TestDoServerRequestAttachesToken (0.01s)150=== CONT TestPartSizeForNAR151=== RUN TestPartSizeForNAR/zero_stays_at_minimum152=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum153=== RUN TestPartSizeForNAR/small_stays_at_minimum154=== PAUSE TestPartSizeForNAR/small_stays_at_minimum155=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum156=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum157=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts158=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts159=== RUN TestPartSizeForNAR/1_TiB160=== PAUSE TestPartSizeForNAR/1_TiB161=== RUN TestPartSizeForNAR/5_TiB_S3_max_object162=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object163=== RUN TestPartSizeForNAR/capped_at_5_GiB164=== PAUSE TestPartSizeForNAR/capped_at_5_GiB165=== CONT TestUploadMultipart_SupersededByPeer166=== RUN TestUploadMultipart_SupersededByPeer/exists167=== PAUSE TestUploadMultipart_SupersededByPeer/exists168=== RUN TestUploadMultipart_SupersededByPeer/missing1692026/09/10 17:37:05 WARN Rate limiter backed off name=server-test rate=5170=== PAUSE TestUploadMultipart_SupersededByPeer/missing1712026/09/10 17:37:05 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49921172=== CONT TestStreamPushIsolatesFailures173--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)174=== CONT TestParsePathInfoJSON175=== RUN TestParsePathInfoJSON/Nix_format176=== PAUSE TestParsePathInfoJSON/Nix_format177=== RUN TestParsePathInfoJSON/Lix_format178=== PAUSE TestParsePathInfoJSON/Lix_format1792026/09/10 17:37:05 ERROR Upload failed error="bad path" count=3180=== RUN TestParsePathInfoJSON/empty_input181=== PAUSE TestParsePathInfoJSON/empty_input182=== RUN TestParsePathInfoJSON/whitespace_only183=== PAUSE TestParsePathInfoJSON/whitespace_only184=== CONT TestParsePathInfoJSONMultiplePaths185--- PASS: TestStreamPushIsolatesFailures (0.00s)186=== RUN TestParsePathInfoJSON/invalid_JSON187=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths188=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths189=== PAUSE TestParsePathInfoJSON/invalid_JSON190=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths191=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths192=== CONT TestFilterOversizedClosures193=== RUN TestFilterOversizedClosures/no_limit_keeps_everything194=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything195=== CONT TestPathInfoHashCompatibility196=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped197=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped198=== RUN TestFilterOversizedClosures/all_closures_skipped199=== PAUSE TestFilterOversizedClosures/all_closures_skipped200=== CONT TestCaseHackSuffix201=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)202=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)203=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon204=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon205=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI206=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI207=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512208=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512209=== CONT TestFileTokenEmpty210--- PASS: TestFileTokenEmpty (0.00s)211=== CONT TestFileTokenMissing212--- PASS: TestFileTokenMissing (0.00s)213=== CONT TestGetStorePathHash214=== RUN TestGetStorePathHash/valid_store_path215=== PAUSE TestGetStorePathHash/valid_store_path216=== RUN TestGetStorePathHash/basename_without_hyphen_should_error217=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error218=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error219=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error220=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error221=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error222=== CONT TestSetClientTLSErrors223=== RUN TestSetClientTLSErrors/missing_cert_file224=== PAUSE TestSetClientTLSErrors/missing_cert_file225=== RUN TestSetClientTLSErrors/missing_key_file226=== PAUSE TestSetClientTLSErrors/missing_key_file227=== RUN TestSetClientTLSErrors/missing_ca_file228=== PAUSE TestSetClientTLSErrors/missing_ca_file229=== RUN TestSetClientTLSErrors/invalid_ca_file230=== PAUSE TestSetClientTLSErrors/invalid_ca_file231=== CONT TestStaticToken232--- PASS: TestStaticToken (0.00s)233=== CONT TestSetClientTLSDoesNotMutateDefaultTransport234--- PASS: TestScriptTokenEmptyToken (0.01s)235=== CONT TestSetClientTLS236--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)237=== CONT TestStreamPushBatchesUnderLoad238--- PASS: TestScriptTokenBadJSON (0.01s)239=== CONT TestConvertHashToNix32/SRI_format_to_Nix32240=== CONT TestEncodeNixBase32/test_string_hash241=== CONT TestConvertHashToNix32/invalid_format242=== CONT TestConvertHashToNix32/already_Nix32_format243--- PASS: TestConvertHashToNix32 (0.00s)244 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)245 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)246 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)247=== CONT TestEncodeNixBase32/empty_input248--- PASS: TestEncodeNixBase32 (0.00s)249 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)250 --- PASS: TestEncodeNixBase32/empty_input (0.00s)251=== CONT TestPathInfoCACompatibility/null_ca_field252=== CONT TestPathInfoCACompatibility/new_structured_format_-_text253=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive254=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method255=== CONT TestPathInfoCACompatibility/old_string_format_-_text256--- PASS: TestPathInfoCACompatibility (0.00s)257 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)258 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)259 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)260 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)261 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)262=== CONT TestRateLimiterFeedback/429_enables_limiter263=== RUN TestSetClientTLS/rejects_connection_without_client_cert264=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert265=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2662026/09/10 17:37:05 WARN Rate limiter enabled after throttle name=server-test rate=5267=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA268=== RUN TestSetClientTLS/preserves_debug_logging_transport269=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2702026/09/10 17:37:05 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:49926271=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2722026/09/10 17:37:05 WARN Rate limiter backed off name=server-test rate=5273=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter274=== CONT TestRateLimiterFeedback/503_enables_limiter2752026/09/10 17:37:05 WARN Rate limiter enabled after throttle name=server-test rate=52762026/09/10 17:37:05 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:49932277=== CONT TestPartSizeForNAR/zero_stays_at_minimum278=== CONT TestUploadMultipart_SupersededByPeer/exists2792026/09/10 17:37:05 WARN Rate limiter backed off name=server-test rate=5280--- PASS: TestRateLimiterFeedback (0.00s)281 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)282 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)283 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)284 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)285=== CONT TestPartSizeForNAR/capped_at_5_GiB286=== CONT TestPartSizeForNAR/5_TiB_S3_max_object287=== CONT TestPartSizeForNAR/1_TiB288=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts289=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum290=== CONT TestPartSizeForNAR/small_stays_at_minimum291--- PASS: TestPartSizeForNAR (0.00s)292 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)293 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)294 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)295 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)296 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)297 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)298 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)299=== CONT TestUploadMultipart_SupersededByPeer/missing300=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths301=== CONT TestParsePathInfoJSON/Nix_format302=== CONT TestParsePathInfoJSON/invalid_JSON303=== CONT TestParsePathInfoJSON/whitespace_only304=== CONT TestParsePathInfoJSON/empty_input305=== CONT TestParsePathInfoJSON/Lix_format306--- PASS: TestParsePathInfoJSON (0.00s)307 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)308 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)309 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)310 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)311 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)312=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths313--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)314 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)315 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)316=== CONT TestFilterOversizedClosures/no_limit_keeps_everything317=== CONT TestFilterOversizedClosures/all_closures_skipped3182026/09/10 17:37:05 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=50319=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3202026/09/10 17:37:05 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=2000321--- PASS: TestFilterOversizedClosures (0.00s)322 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)323 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)324 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)325=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)326=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI327=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512328=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon329--- PASS: TestPathInfoHashCompatibility (0.00s)330 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)331 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)332 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)333 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)334=== CONT TestGetStorePathHash/valid_store_path335=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error336=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error337=== CONT TestGetStorePathHash/basename_without_hyphen_should_error338--- PASS: TestGetStorePathHash (0.00s)339 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)340 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)341 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)342 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)343=== CONT TestSetClientTLSErrors/missing_cert_file344=== CONT TestSetClientTLSErrors/missing_ca_file345--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)347 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)348=== CONT TestSetClientTLSErrors/invalid_ca_file349=== CONT TestSetClientTLSErrors/missing_key_file350=== CONT TestSetClientTLS/rejects_connection_without_client_cert351=== CONT TestSetClientTLS/preserves_debug_logging_transport352--- PASS: TestSetClientTLSErrors (0.00s)353 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)354 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)355 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)356 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)357=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3582026/09/10 17:37:05 http: TLS handshake error from 127.0.0.1:49939: read tcp 127.0.0.1:49925->127.0.0.1:49939: use of closed network connection359--- PASS: TestSetClientTLS (0.00s)360 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)361 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)362 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)363--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)364--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)365--- PASS: TestDumpPathWriterError (0.04s)366--- PASS: TestDumpPathSingleFile (0.05s)367--- PASS: TestCaseHackSuffix (0.04s)368--- PASS: TestDumpPathMatchesNix (0.06s)369--- PASS: TestStreamPushBatchesUnderLoad (0.10s)370--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)371PASS372Running server tests...373The files belonging to this database system will be owned by user "_nixbld1".374This user must also own the server process.375376The database cluster will be initialized with locale "C".377The default database encoding has accordingly been set to "SQL_ASCII".378The default text search configuration will be set to "english".379380Data page checksums are enabled.381382creating directory /nix/var/nix/builds/nix-99207-761247270/postgres3315033572/data ... ok383creating subdirectories ... ok384selecting dynamic shared memory implementation ... posix385selecting default "max_connections" ... 100386selecting default "shared_buffers" ... 128MB387selecting default time zone ... UTC388creating configuration files ... ok389running bootstrap script ... ok390performing post-bootstrap initialization ... ok391syncing data to disk ... ok392393initdb: warning: enabling "trust" authentication for local connections394initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.395396Success. You can now start the database server using:397398 pg_ctl -D /nix/var/nix/builds/nix-99207-761247270/postgres3315033572/data -l logfile start399400/nix/var/nix/builds/nix-99207-761247270/postgres3315033572:5432 - no response4012026-09-10 17:37:07.658 UTC [99426] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4022026-09-10 17:37:07.658 UTC [99426] LOG: listening on Unix socket "/nix/var/nix/builds/nix-99207-761247270/postgres3315033572/.s.PGSQL.5432"4032026-09-10 17:37:07.661 UTC [99433] LOG: database system was shut down at 2026-09-10 17:37:07 UTC4042026-09-10 17:37:07.662 UTC [99426] LOG: database system is ready to accept connections405/nix/var/nix/builds/nix-99207-761247270/postgres3315033572:5432 - accepting connections406=== RUN TestService_AuthMiddleware407=== PAUSE TestService_AuthMiddleware408=== RUN TestService_AuthMiddleware_MTLSProxyHeader409=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader410=== RUN TestService_AuthMiddleware_MTLSBoundSubjects411=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects412=== RUN TestService_ReadAuthMiddleware413=== PAUSE TestService_ReadAuthMiddleware414=== RUN TestService_AuthMiddleware_OIDC415=== PAUSE TestService_AuthMiddleware_OIDC416=== RUN TestService_RequireScope_OIDC417=== PAUSE TestService_RequireScope_OIDC418=== RUN TestService_ReadScope_PublicByDefault419=== PAUSE TestService_ReadScope_PublicByDefault420=== RUN TestCacheConfigHandler421=== PAUSE TestCacheConfigHandler422=== RUN TestCacheStatsHandler423=== PAUSE TestCacheStatsHandler424=== RUN TestClaim_BuildWaitComplete425=== PAUSE TestClaim_BuildWaitComplete426=== RUN TestClaim_GCMarkedOutputCountsAsAbsent427=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent428=== RUN TestClaim_TooManyStreams429=== PAUSE TestClaim_TooManyStreams430=== RUN TestClaim_HolderDisconnectKeepsClaim431=== PAUSE TestClaim_HolderDisconnectKeepsClaim432=== RUN TestClaim_FailWakesWaitersButIsNotRemembered433=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered434=== RUN TestClaim_FailWithoutKindReleases435=== PAUSE TestClaim_FailWithoutKindReleases436=== RUN TestClaim_StaleHeartbeatStolen437=== PAUSE TestClaim_StaleHeartbeatStolen438=== RUN TestClaim_TwoInstances439=== PAUSE TestClaim_TwoInstances440=== RUN TestClaim_InputsTouched441=== PAUSE TestClaim_InputsTouched442=== RUN TestClaim_StreamsThroughServer443=== PAUSE TestClaim_StreamsThroughServer444=== RUN TestClientCADerivations445=== PAUSE TestClientCADerivations446=== RUN TestClientErrorHandling447=== PAUSE TestClientErrorHandling448=== RUN TestClientIntegration449=== PAUSE TestClientIntegration450=== RUN TestClientMultipleUploads451=== PAUSE TestClientMultipleUploads452=== RUN TestClientWithDependencies453=== PAUSE TestClientWithDependencies454=== RUN TestPinProtectsFromGC455=== PAUSE TestPinProtectsFromGC456=== RUN TestResolveDBConnectionString457=== PAUSE TestResolveDBConnectionString458=== RUN TestGCAdvisoryLockBlocksConcurrentRun4592026-09-10 17:37:07.930 UTC [99505] ERROR: relation "goose_db_version" does not exist at character 364602026-09-10 17:37:07.930 UTC [99505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4612026/09/10 17:37:07 OK 20241026095416_initial_model.sql (3.88ms)4622026/09/10 17:37:07 OK 20251210153512_drop_unused_gin_index.sql (652.17µs)4632026/09/10 17:37:07 OK 20251218171726_add_pins.sql (791.96µs)4642026/09/10 17:37:07 OK 20260628120000_add_object_size_and_stats.sql (889.13µs)4652026/09/10 17:37:07 OK 20260905000000_add_claims.sql (968.83µs)4662026/09/10 17:37:07 goose: successfully migrated database to version: 202609050000004672026/09/10 17:37:07 OK 1_commit_pending_closure.sql (978.29µs)4682026/09/10 17:37:07 OK 2_object_stats_trigger.sql (233.5µs)4692026/09/10 17:37:07 goose: up to current file version: 2470--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.14s)471=== RUN TestGCBugBareHashReferences472=== PAUSE TestGCBugBareHashReferences473=== RUN TestGCMetrics474=== PAUSE TestGCMetrics475=== RUN TestGCTaskStore_StartNew476=== PAUSE TestGCTaskStore_StartNew477=== RUN TestGCTaskStore_DeduplicateSameParams478=== PAUSE TestGCTaskStore_DeduplicateSameParams479=== RUN TestGCTaskStore_ConflictDifferentParams480=== PAUSE TestGCTaskStore_ConflictDifferentParams481=== RUN TestGCTaskStore_GetEmpty482=== PAUSE TestGCTaskStore_GetEmpty483=== RUN TestGCTaskStore_GetReturnsLatest484=== PAUSE TestGCTaskStore_GetReturnsLatest485=== RUN TestGCTaskStore_CompletedAllowsNewTask486=== PAUSE TestGCTaskStore_CompletedAllowsNewTask487=== RUN TestGCTaskStore_PhaseUpdates488=== PAUSE TestGCTaskStore_PhaseUpdates489=== RUN TestGCTaskStore_Fail490=== PAUSE TestGCTaskStore_Fail491=== RUN TestGracefulShutdownDrainsInflight492=== PAUSE TestGracefulShutdownDrainsInflight493=== RUN TestService_healthCheckHandler494=== PAUSE TestService_healthCheckHandler495=== RUN TestService_readinessHandler496=== PAUSE TestService_readinessHandler497=== RUN TestGenerateLandingPage498=== PAUSE TestGenerateLandingPage499=== RUN TestCacheConfigHandlerMaxNarSize500=== PAUSE TestCacheConfigHandlerMaxNarSize501=== RUN TestCreatePendingClosureRejectsOversizedNAR502=== PAUSE TestCreatePendingClosureRejectsOversizedNAR503=== RUN TestNARDeduplicationMetadataUploadBug504=== PAUSE TestNARDeduplicationMetadataUploadBug505=== RUN TestMetricsInventory506=== PAUSE TestMetricsInventory507=== RUN TestService_NativeMTLS508=== PAUSE TestService_NativeMTLS509=== RUN TestServerTLSConfig510=== PAUSE TestServerTLSConfig511=== RUN TestMultipartCleanup512=== PAUSE TestMultipartCleanup513=== RUN TestObjectStatsTrigger514=== PAUSE TestObjectStatsTrigger515=== RUN TestOrphanedObjectsGC516=== PAUSE TestOrphanedObjectsGC517=== RUN TestOrphanedObjectsGCStressTest518=== PAUSE TestOrphanedObjectsGCStressTest519=== RUN TestResurrectedObjectNotDeleted520=== PAUSE TestResurrectedObjectNotDeleted521=== RUN TestParseSingleRange522=== PAUSE TestParseSingleRange523=== RUN TestIsValidCachePath524=== PAUSE TestIsValidCachePath525=== RUN TestReadProxyNarinfo526=== PAUSE TestReadProxyNarinfo527=== RUN TestReadProxyNarinfoAlreadyDecompressed528=== PAUSE TestReadProxyNarinfoAlreadyDecompressed529=== RUN TestReadProxyNarStreaming530=== PAUSE TestReadProxyNarStreaming531=== RUN TestReadProxy404532=== PAUSE TestReadProxy404533=== RUN TestReadProxyInvalidPath534=== PAUSE TestReadProxyInvalidPath535=== RUN TestReadProxyHead536=== PAUSE TestReadProxyHead537=== RUN TestReadProxyConditionalGet538=== PAUSE TestReadProxyConditionalGet539=== RUN TestReadProxyRootRedirectsToIndexHTML540=== PAUSE TestReadProxyRootRedirectsToIndexHTML541=== RUN TestReadProxyDisabled542=== PAUSE TestReadProxyDisabled543=== RUN TestReadRedirectNar544=== PAUSE TestReadRedirectNar545=== RUN TestReadRedirectKeepsNarinfoProxied546=== PAUSE TestReadRedirectKeepsNarinfoProxied547=== RUN TestReadProxyRangeRequest548=== PAUSE TestReadProxyRangeRequest549=== RUN TestReadRedirectUsesPublicS3URL550=== PAUSE TestReadRedirectUsesPublicS3URL551=== RUN TestRedundantMultipartUpload552=== PAUSE TestRedundantMultipartUpload553=== RUN TestCompleteMultipartUpload_ErrorButObjectExists554=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists555=== RUN TestCompletedNarNotReofferedAcrossClosures556=== PAUSE TestCompletedNarNotReofferedAcrossClosures557=== RUN TestPresignedUploadRegisteredBeforeCommit558=== PAUSE TestPresignedUploadRegisteredBeforeCommit559=== RUN TestService_Rustfstest560=== PAUSE TestService_Rustfstest561=== RUN TestParseSize562=== PAUSE TestParseSize563=== RUN TestSkippedUploadsHandler564=== PAUSE TestSkippedUploadsHandler565=== RUN TestSystemdListenerNotActivated566--- PASS: TestSystemdListenerNotActivated (0.00s)567=== RUN TestWatchdogBeatsWhenHealthy568--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)569=== RUN TestWatchdogSkipsWhenUnhealthy5702026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/10 17:37:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"580--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)581=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle582=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle583=== RUN TestProxyWriteTimeout584=== PAUSE TestProxyWriteTimeout585=== RUN TestIsValidUploadKey586=== PAUSE TestIsValidUploadKey587=== RUN TestUploadHandlersRejectInvalidKeys588=== PAUSE TestUploadHandlersRejectInvalidKeys589=== RUN TestUploadHandlersRejectOversizedBody590=== PAUSE TestUploadHandlersRejectOversizedBody591=== RUN TestService_cleanupPendingClosuresHandler592=== PAUSE TestService_cleanupPendingClosuresHandler593=== RUN TestService_createPendingClosureHandler594=== PAUSE TestService_createPendingClosureHandler595=== RUN TestService_verifyS3Integrity596=== PAUSE TestService_verifyS3Integrity597=== RUN TestCompleteMultipartUnregistered598=== PAUSE TestCompleteMultipartUnregistered599=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT600=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT601=== CONT TestService_AuthMiddleware602=== CONT TestNARDeduplicationMetadataUploadBug603=== CONT TestReadRedirectKeepsNarinfoProxied604=== CONT TestReadProxyNarinfo605=== CONT TestReadProxyHead606=== CONT TestReadProxy404607=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT608=== CONT TestCompleteMultipartUnregistered609=== CONT TestService_verifyS3Integrity610=== CONT TestService_createPendingClosureHandler6112026-09-10 17:37:08.464 UTC [99535] ERROR: relation "goose_db_version" does not exist at character 366122026-09-10 17:37:08.464 UTC [99535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6132026/09/10 17:37:08 OK 20241026095416_initial_model.sql (14.5ms)6142026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)6152026/09/10 17:37:08 OK 20251218171726_add_pins.sql (3.65ms)6162026-09-10 17:37:08.505 UTC [99537] ERROR: relation "goose_db_version" does not exist at character 366172026-09-10 17:37:08.505 UTC [99537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6182026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)6192026-09-10 17:37:08.508 UTC [99538] ERROR: relation "goose_db_version" does not exist at character 366202026-09-10 17:37:08.508 UTC [99538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6212026/09/10 17:37:08 OK 20260905000000_add_claims.sql (3.55ms)6222026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000006232026/09/10 17:37:08 OK 1_commit_pending_closure.sql (1.93ms)6242026-09-10 17:37:08.511 UTC [99543] ERROR: relation "goose_db_version" does not exist at character 366252026-09-10 17:37:08.511 UTC [99543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6262026-09-10 17:37:08.511 UTC [99541] ERROR: relation "goose_db_version" does not exist at character 366272026-09-10 17:37:08.511 UTC [99541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6282026-09-10 17:37:08.511 UTC [99539] ERROR: relation "goose_db_version" does not exist at character 366292026-09-10 17:37:08.511 UTC [99539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6302026-09-10 17:37:08.511 UTC [99542] ERROR: relation "goose_db_version" does not exist at character 366312026-09-10 17:37:08.511 UTC [99542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6322026-09-10 17:37:08.511 UTC [99540] ERROR: relation "goose_db_version" does not exist at character 366332026-09-10 17:37:08.511 UTC [99540] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6342026-09-10 17:37:08.511 UTC [99545] ERROR: relation "goose_db_version" does not exist at character 366352026-09-10 17:37:08.511 UTC [99545] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6362026-09-10 17:37:08.511 UTC [99544] ERROR: relation "goose_db_version" does not exist at character 366372026-09-10 17:37:08.511 UTC [99544] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026/09/10 17:37:08 OK 2_object_stats_trigger.sql (1.05ms)6392026/09/10 17:37:08 goose: up to current file version: 26402026/09/10 17:37:08 OK 20241026095416_initial_model.sql (6.44ms)6412026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (23.01ms)6422026/09/10 17:37:08 OK 20241026095416_initial_model.sql (31.42ms)6432026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (6.48ms)6442026/09/10 17:37:08 OK 20251218171726_add_pins.sql (7.69ms)6452026/09/10 17:37:08 OK 20251218171726_add_pins.sql (14.71ms)6462026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (8.21ms)6472026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (8.36ms)6482026/09/10 17:37:08 OK 20241026095416_initial_model.sql (49.17ms)6492026/09/10 17:37:08 OK 20241026095416_initial_model.sql (49.27ms)6502026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)6512026/09/10 17:37:08 OK 20241026095416_initial_model.sql (49.94ms)6522026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (8.11ms)6532026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (7.62ms)6542026/09/10 17:37:08 OK 20241026095416_initial_model.sql (63.92ms)6552026/09/10 17:37:08 OK 20251218171726_add_pins.sql (6.47ms)6562026/09/10 17:37:08 OK 20241026095416_initial_model.sql (64.98ms)6572026/09/10 17:37:08 OK 20251218171726_add_pins.sql (14.3ms)6582026/09/10 17:37:08 OK 20241026095416_initial_model.sql (64.52ms)6592026/09/10 17:37:08 OK 20251218171726_add_pins.sql (7.91ms)6602026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)6612026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (8.11ms)6622026/09/10 17:37:08 OK 20260905000000_add_claims.sql (24.41ms)6632026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000006642026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (8.05ms)6652026/09/10 17:37:08 OK 20260905000000_add_claims.sql (24.47ms)6662026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000006672026/09/10 17:37:08 OK 20241026095416_initial_model.sql (71.44ms)6682026/09/10 17:37:08 OK 1_commit_pending_closure.sql (1.5ms)6692026/09/10 17:37:08 OK 1_commit_pending_closure.sql (1.51ms)6702026/09/10 17:37:08 OK 2_object_stats_trigger.sql (221.46µs)6712026/09/10 17:37:08 goose: up to current file version: 26722026/09/10 17:37:08 OK 2_object_stats_trigger.sql (212.75µs)6732026/09/10 17:37:08 goose: up to current file version: 26742026/09/10 17:37:08 OK 20251210153512_drop_unused_gin_index.sql (7.17ms)6752026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (16.51ms)6762026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (15.84ms)6772026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (16.77ms)6782026/09/10 17:37:08 OK 20251218171726_add_pins.sql (8.88ms)6792026/09/10 17:37:08 OK 20251218171726_add_pins.sql (9.59ms)6802026/09/10 17:37:08 OK 20251218171726_add_pins.sql (9.18ms)6812026/09/10 17:37:08 OK 20251218171726_add_pins.sql (6.86ms)6822026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (11.92ms)6832026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (12.16ms)6842026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (11.92ms)6852026/09/10 17:37:08 OK 20260905000000_add_claims.sql (18.6ms)6862026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000006872026/09/10 17:37:08 OK 20260905000000_add_claims.sql (25.28ms)6882026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000006892026/09/10 17:37:08 OK 20260905000000_add_claims.sql (25.23ms)6902026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000006912026/09/10 17:37:08 OK 1_commit_pending_closure.sql (7.26ms)6922026/09/10 17:37:08 OK 2_object_stats_trigger.sql (2.88ms)6932026/09/10 17:37:08 goose: up to current file version: 26942026/09/10 17:37:08 OK 1_commit_pending_closure.sql (8.42ms)6952026/09/10 17:37:08 OK 1_commit_pending_closure.sql (8.5ms)6962026/09/10 17:37:08 OK 20260628120000_add_object_size_and_stats.sql (27.34ms)6972026/09/10 17:37:08 OK 20260905000000_add_claims.sql (21.45ms)6982026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000006992026/09/10 17:37:08 OK 20260905000000_add_claims.sql (21.82ms)7002026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000007012026/09/10 17:37:08 OK 20260905000000_add_claims.sql (21.9ms)7022026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000007032026/09/10 17:37:08 OK 2_object_stats_trigger.sql (1.75ms)7042026/09/10 17:37:08 goose: up to current file version: 27052026/09/10 17:37:08 OK 2_object_stats_trigger.sql (1.87ms)7062026/09/10 17:37:08 goose: up to current file version: 27072026/09/10 17:37:08 OK 1_commit_pending_closure.sql (1.9ms)7082026/09/10 17:37:08 OK 2_object_stats_trigger.sql (3.1ms)7092026/09/10 17:37:08 goose: up to current file version: 27102026/09/10 17:37:08 OK 1_commit_pending_closure.sql (5.65ms)7112026/09/10 17:37:08 OK 2_object_stats_trigger.sql (5.57ms)7122026/09/10 17:37:08 goose: up to current file version: 27132026/09/10 17:37:08 OK 1_commit_pending_closure.sql (12.53ms)7142026/09/10 17:37:08 OK 20260905000000_add_claims.sql (13.08ms)7152026/09/10 17:37:08 goose: successfully migrated database to version: 202609050000007162026/09/10 17:37:08 OK 2_object_stats_trigger.sql (4.79ms)7172026/09/10 17:37:08 goose: up to current file version: 27182026/09/10 17:37:08 OK 1_commit_pending_closure.sql (9.23ms)7192026/09/10 17:37:08 OK 2_object_stats_trigger.sql (4.53ms)7202026/09/10 17:37:08 goose: up to current file version: 27212026/09/10 17:37:08 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"722--- PASS: TestService_AuthMiddleware (0.43s)723=== CONT TestService_cleanupPendingClosuresHandler724--- PASS: TestReadProxyNarinfo (0.59s)725=== CONT TestUploadHandlersRejectOversizedBody726=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure727=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure728=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart729=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart730=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts731=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts732=== CONT TestUploadHandlersRejectInvalidKeys733=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info734=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info735=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal736=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal737=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key738=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key739=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key740=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key741=== CONT TestIsValidUploadKey742=== RUN TestIsValidUploadKey/narinfo743=== PAUSE TestIsValidUploadKey/narinfo744=== RUN TestIsValidUploadKey/nar_zst745=== PAUSE TestIsValidUploadKey/nar_zst746=== RUN TestIsValidUploadKey/nar_xz747=== PAUSE TestIsValidUploadKey/nar_xz748=== RUN TestIsValidUploadKey/nar_plain749=== PAUSE TestIsValidUploadKey/nar_plain750=== RUN TestIsValidUploadKey/listing751=== PAUSE TestIsValidUploadKey/listing752=== RUN TestIsValidUploadKey/build_log753=== PAUSE TestIsValidUploadKey/build_log754=== RUN TestIsValidUploadKey/build_log_home-manager_file755=== PAUSE TestIsValidUploadKey/build_log_home-manager_file756=== RUN TestIsValidUploadKey/build_log_plus_in_name757=== PAUSE TestIsValidUploadKey/build_log_plus_in_name758=== RUN TestIsValidUploadKey/build_log_question_mark759=== PAUSE TestIsValidUploadKey/build_log_question_mark760=== RUN TestIsValidUploadKey/build_log_equals761=== PAUSE TestIsValidUploadKey/build_log_equals762=== RUN TestIsValidUploadKey/realisation763=== PAUSE TestIsValidUploadKey/realisation764=== RUN TestIsValidUploadKey/realisation_plus_in_output765=== PAUSE TestIsValidUploadKey/realisation_plus_in_output766=== RUN TestIsValidUploadKey/nix-cache-info767=== PAUSE TestIsValidUploadKey/nix-cache-info768=== RUN TestIsValidUploadKey/index.html769=== PAUSE TestIsValidUploadKey/index.html770=== RUN TestIsValidUploadKey/narinfo_key,_nar_type771=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type772=== RUN TestIsValidUploadKey/nar_key,_narinfo_type773=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type774=== RUN TestIsValidUploadKey/listing_key,_narinfo_type775=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type776=== RUN TestIsValidUploadKey/traversal777=== PAUSE TestIsValidUploadKey/traversal778=== RUN TestIsValidUploadKey/traversal_nar779=== PAUSE TestIsValidUploadKey/traversal_nar780=== RUN TestIsValidUploadKey/absolute781=== PAUSE TestIsValidUploadKey/absolute782=== RUN TestIsValidUploadKey/empty_key783=== PAUSE TestIsValidUploadKey/empty_key784=== RUN TestIsValidUploadKey/unknown_type785=== PAUSE TestIsValidUploadKey/unknown_type786=== CONT TestProxyWriteTimeout787=== RUN TestProxyWriteTimeout/narinfo788=== PAUSE TestProxyWriteTimeout/narinfo789=== RUN TestProxyWriteTimeout/1_GiB_nar790=== PAUSE TestProxyWriteTimeout/1_GiB_nar791=== RUN TestProxyWriteTimeout/10_GiB_nar792=== PAUSE TestProxyWriteTimeout/10_GiB_nar793=== RUN TestProxyWriteTimeout/unknown_size794=== PAUSE TestProxyWriteTimeout/unknown_size795=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle7962026/09/10 17:37:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7972026/09/10 17:37:08 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst798--- PASS: TestCompleteMultipartUnregistered (0.71s)799=== CONT TestSkippedUploadsHandler8002026/09/10 17:37:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000801--- PASS: TestSkippedUploadsHandler (0.00s)802=== CONT TestParseSize803--- PASS: TestParseSize (0.00s)804=== CONT TestService_Rustfstest8052026/09/10 17:37:09 INFO Received uploads request method=POST path=/api/pending_closures8062026/09/10 17:37:09 INFO Received uploads request method=POST path=/api/pending_closures8072026/09/10 17:37:09 INFO Received uploads request method=POST path=/api/pending_closures8082026-09-10 17:37:09.107 UTC [99571] ERROR: relation "goose_db_version" does not exist at character 368092026-09-10 17:37:09.107 UTC [99571] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026-09-10 17:37:09.133 UTC [99573] ERROR: relation "goose_db_version" does not exist at character 368112026-09-10 17:37:09.133 UTC [99573] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026-09-10 17:37:09.142 UTC [99575] ERROR: relation "goose_db_version" does not exist at character 368132026-09-10 17:37:09.142 UTC [99575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026/09/10 17:37:09 OK 20241026095416_initial_model.sql (9.7ms)8152026/09/10 17:37:09 OK 20251210153512_drop_unused_gin_index.sql (20.39ms)8162026/09/10 17:37:09 OK 20251218171726_add_pins.sql (14.67ms)8172026/09/10 17:37:09 OK 20260628120000_add_object_size_and_stats.sql (9.05ms)8182026/09/10 17:37:09 OK 20241026095416_initial_model.sql (38.26ms)8192026/09/10 17:37:09 OK 20241026095416_initial_model.sql (59.91ms)8202026/09/10 17:37:09 OK 20251210153512_drop_unused_gin_index.sql (10.97ms)8212026/09/10 17:37:09 OK 20260905000000_add_claims.sql (32.33ms)8222026/09/10 17:37:09 goose: successfully migrated database to version: 202609050000008232026/09/10 17:37:09 OK 20251210153512_drop_unused_gin_index.sql (10.77ms)8242026/09/10 17:37:09 OK 1_commit_pending_closure.sql (6.4ms)8252026/09/10 17:37:09 OK 2_object_stats_trigger.sql (246.13µs)8262026/09/10 17:37:09 goose: up to current file version: 28272026/09/10 17:37:09 OK 20251218171726_add_pins.sql (12.65ms)8282026/09/10 17:37:09 OK 20251218171726_add_pins.sql (12.76ms)8292026/09/10 17:37:09 OK 20260628120000_add_object_size_and_stats.sql (16.7ms)8302026/09/10 17:37:09 OK 20260628120000_add_object_size_and_stats.sql (11.15ms)8312026/09/10 17:37:09 OK 20260905000000_add_claims.sql (13.88ms)8322026/09/10 17:37:09 goose: successfully migrated database to version: 202609050000008332026/09/10 17:37:09 OK 20260905000000_add_claims.sql (14.09ms)8342026/09/10 17:37:09 goose: successfully migrated database to version: 202609050000008352026/09/10 17:37:09 OK 1_commit_pending_closure.sql (1.31ms)8362026/09/10 17:37:09 OK 1_commit_pending_closure.sql (1.36ms)8372026/09/10 17:37:09 OK 2_object_stats_trigger.sql (217.96µs)8382026/09/10 17:37:09 goose: up to current file version: 28392026/09/10 17:37:09 OK 2_object_stats_trigger.sql (210.63µs)8402026/09/10 17:37:09 goose: up to current file version: 2841--- PASS: TestReadProxy404 (1.05s)842=== CONT TestPresignedUploadRegisteredBeforeCommit843--- PASS: TestReadRedirectKeepsNarinfoProxied (1.23s)844=== CONT TestCreatePendingClosureRejectsOversizedNAR8452026/09/10 17:37:09 INFO Received uploads request method=POST path=/api/pending_closures846--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)847=== CONT TestCompletedNarNotReofferedAcrossClosures848--- PASS: TestReadProxyHead (1.38s)849=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8502026-09-10 17:37:09.794 UTC [99607] ERROR: relation "goose_db_version" does not exist at character 368512026-09-10 17:37:09.794 UTC [99607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8522026/09/10 17:37:09 INFO Received uploads request method=POST path=/api/pending_closures853--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.63s)854=== CONT TestCacheConfigHandlerMaxNarSize855--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)856=== CONT TestRedundantMultipartUpload8572026/09/10 17:37:09 OK 20241026095416_initial_model.sql (112.2ms)8582026/09/10 17:37:09 OK 20251210153512_drop_unused_gin_index.sql (7.16ms)8592026/09/10 17:37:09 OK 20251218171726_add_pins.sql (23.04ms)8602026/09/10 17:37:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8612026/09/10 17:37:09 OK 20260628120000_add_object_size_and_stats.sql (26.05ms)8622026/09/10 17:37:10 OK 20260905000000_add_claims.sql (30.68ms)8632026/09/10 17:37:10 goose: successfully migrated database to version: 202609050000008642026/09/10 17:37:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LmI1NTRjMDM5LWNkZDItNGExYi05NmE5LWQ5ZDhkY2Q1MmExMHgxNzg5MDYxODI5MDk4NTAwMDAw parts=108652026/09/10 17:37:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8662026/09/10 17:37:10 OK 1_commit_pending_closure.sql (6.97ms)8672026/09/10 17:37:10 OK 2_object_stats_trigger.sql (390.5µs)8682026/09/10 17:37:10 goose: up to current file version: 28692026/09/10 17:37:10 INFO Completed upload id=18702026/09/10 17:37:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008712026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures8722026/09/10 17:37:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures8732026/09/10 17:37:10 INFO Aborted multipart uploads count=08742026/09/10 17:37:10 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=08752026/09/10 17:37:10 INFO Vacuumed table table=pending_closures8762026/09/10 17:37:10 INFO Vacuumed table table=pending_objects8772026/09/10 17:37:10 INFO Vacuumed table table=multipart_uploads8782026/09/10 17:37:10 INFO Vacuumed table table=closures8792026/09/10 17:37:10 INFO Vacuumed table table=objects880=== NAME TestNARDeduplicationMetadataUploadBug881 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-99207-761247270/TestNARDeduplicationMetadataUploadBug2169038047/001/store/advipn4hqxfx7wkqh8paavi5649bbw1b-file1.txt8822026-09-10 17:37:10.117 UTC [99619] ERROR: relation "goose_db_version" does not exist at character 368832026-09-10 17:37:10.117 UTC [99619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8842026/09/10 17:37:10 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000885--- PASS: TestService_createPendingClosureHandler (1.89s)886=== CONT TestGenerateLandingPage887--- PASS: TestGenerateLandingPage (0.00s)888=== CONT TestReadRedirectUsesPublicS3URL8892026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures8902026/09/10 17:37:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8912026/09/10 17:37:10 OK 20241026095416_initial_model.sql (44.83ms)8922026/09/10 17:37:10 OK 20251210153512_drop_unused_gin_index.sql (5.5ms)8932026/09/10 17:37:10 OK 20251218171726_add_pins.sql (5.18ms)8942026/09/10 17:37:10 OK 20260628120000_add_object_size_and_stats.sql (19.87ms)8952026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures8962026/09/10 17:37:10 OK 20260905000000_add_claims.sql (34.47ms)8972026/09/10 17:37:10 goose: successfully migrated database to version: 202609050000008982026/09/10 17:37:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8992026/09/10 17:37:10 INFO Uploading advipn4hqxfx7wkqh8paavi5649bbw1b-file1.txt (160B)9002026/09/10 17:37:10 OK 1_commit_pending_closure.sql (7.32ms)9012026/09/10 17:37:10 OK 2_object_stats_trigger.sql (335.71µs)9022026/09/10 17:37:10 goose: up to current file version: 29032026/09/10 17:37:10 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9042026/09/10 17:37:10 WARN Failed to register uploaded object key=advipn4hqxfx7wkqh8paavi5649bbw1b.ls error="server returned 404: 404 page not found\n"9052026/09/10 17:37:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9062026/09/10 17:37:10 INFO Signed narinfos id=1 count=19072026/09/10 17:37:10 INFO Uploading 1 narinfos9082026/09/10 17:37:10 WARN Failed to register uploaded object key=advipn4hqxfx7wkqh8paavi5649bbw1b.narinfo error="server returned 404: 404 page not found\n"9092026/09/10 17:37:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9102026/09/10 17:37:10 INFO Completed upload id=19112026/09/10 17:37:10 INFO Upload complete. (184ms)912=== NAME TestNARDeduplicationMetadataUploadBug913 metadata_upload_test.go:54: Retrieved narinfo from S3:914 StorePath: /nix/var/nix/builds/nix-99207-761247270/TestNARDeduplicationMetadataUploadBug2169038047/001/store/advipn4hqxfx7wkqh8paavi5649bbw1b-file1.txt915 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst916 Compression: zstd917 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf918 NarSize: 160919 References: 920 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf921 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)922 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):923 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9242026/09/10 17:37:10 INFO Received cleanup request method=DELETE path=/api/pending_closures9252026/09/10 17:37:10 INFO Aborted multipart uploads count=09262026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures9272026/09/10 17:37:10 INFO Received cleanup request method=DELETE path=/api/pending_closures9282026/09/10 17:37:10 INFO Aborted multipart uploads count=1929 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-99207-761247270/TestNARDeduplicationMetadataUploadBug2169038047/001/store/rym7rkzr8ykny6f4n4s77llvy1mcifgi-file2.txt9302026/09/10 17:37:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9312026-09-10 17:37:10.387 UTC [99571] ERROR: Closure does not exist: id=19322026-09-10 17:37:10.387 UTC [99571] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9332026-09-10 17:37:10.387 UTC [99571] STATEMENT: -- name: CommitPendingClosure :exec934 SELECT commit_pending_closure($1::bigint)935 936--- PASS: TestService_cleanupPendingClosuresHandler (1.71s)937=== CONT TestReadProxyInvalidPath9382026/09/10 17:37:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9392026-09-10 17:37:10.474 UTC [99649] ERROR: relation "goose_db_version" does not exist at character 369402026-09-10 17:37:10.474 UTC [99649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9412026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures9422026/09/10 17:37:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9432026/09/10 17:37:10 WARN Failed to register uploaded object key=rym7rkzr8ykny6f4n4s77llvy1mcifgi.ls error="server returned 404: 404 page not found\n"9442026/09/10 17:37:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9452026/09/10 17:37:10 INFO Signed narinfos id=2 count=19462026/09/10 17:37:10 INFO Uploading 1 narinfos9472026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures9482026/09/10 17:37:10 WARN Failed to register uploaded object key=rym7rkzr8ykny6f4n4s77llvy1mcifgi.narinfo error="server returned 404: 404 page not found\n"9492026/09/10 17:37:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9502026/09/10 17:37:10 INFO Completed upload id=29512026/09/10 17:37:10 INFO Upload complete. (121ms)952=== NAME TestNARDeduplicationMetadataUploadBug953 metadata_upload_test.go:76: Retrieved narinfo from S3:954 StorePath: /nix/var/nix/builds/nix-99207-761247270/TestNARDeduplicationMetadataUploadBug2169038047/001/store/rym7rkzr8ykny6f4n4s77llvy1mcifgi-file2.txt955 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst956 Compression: zstd957 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf958 NarSize: 160959 References: 960 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf961 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)962 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):963 {"version":1,"root":{"type":"regular","size":44}}964--- PASS: TestNARDeduplicationMetadataUploadBug (2.33s)965=== CONT TestService_readinessHandler9662026/09/10 17:37:10 OK 20241026095416_initial_model.sql (94.67ms)9672026/09/10 17:37:10 OK 20251210153512_drop_unused_gin_index.sql (5.69ms)9682026/09/10 17:37:10 OK 20251218171726_add_pins.sql (23.97ms)9692026/09/10 17:37:10 OK 20260628120000_add_object_size_and_stats.sql (25.64ms)9702026/09/10 17:37:10 OK 20260905000000_add_claims.sql (46.25ms)9712026/09/10 17:37:10 goose: successfully migrated database to version: 202609050000009722026/09/10 17:37:10 OK 1_commit_pending_closure.sql (1.51ms)9732026/09/10 17:37:10 OK 2_object_stats_trigger.sql (216.46µs)9742026/09/10 17:37:10 goose: up to current file version: 2975--- PASS: TestService_Rustfstest (1.80s)976=== CONT TestReadProxyDisabled9772026/09/10 17:37:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9782026-09-10 17:37:10.906 UTC [99664] ERROR: relation "goose_db_version" does not exist at character 369792026-09-10 17:37:10.906 UTC [99664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9802026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures9812026/09/10 17:37:10 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9822026/09/10 17:37:10 INFO Received uploads request method=POST path=/api/pending_closures983--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.70s)984=== CONT TestReadRedirectNar9852026/09/10 17:37:11 OK 20241026095416_initial_model.sql (96.48ms)9862026/09/10 17:37:11 OK 20251210153512_drop_unused_gin_index.sql (10.58ms)9872026/09/10 17:37:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9882026/09/10 17:37:11 OK 20251218171726_add_pins.sql (19.3ms)9892026/09/10 17:37:11 OK 20260628120000_add_object_size_and_stats.sql (22.22ms)9902026/09/10 17:37:11 OK 20260905000000_add_claims.sql (25.34ms)9912026/09/10 17:37:11 goose: successfully migrated database to version: 202609050000009922026/09/10 17:37:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LmZkYWU3NTIyLWVmMzYtNGMzNi1hZTRhLTU0N2U5Y2Y4ZmM0OHgxNzg5MDYxODMwMTYwMDk4MDAw parts=109932026/09/10 17:37:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9942026/09/10 17:37:11 OK 1_commit_pending_closure.sql (7.34ms)9952026/09/10 17:37:11 INFO Completed upload id=19962026/09/10 17:37:11 OK 2_object_stats_trigger.sql (4.04ms)9972026/09/10 17:37:11 goose: up to current file version: 29982026-09-10 17:37:11.176 UTC [99670] ERROR: relation "goose_db_version" does not exist at character 369992026-09-10 17:37:11.176 UTC [99670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10002026/09/10 17:37:11 INFO Received uploads request method=POST path=/api/pending_closures10012026/09/10 17:37:11 INFO Received uploads request method=POST path=/api/pending_closures10022026/09/10 17:37:11 INFO Received uploads request method=POST path=/api/pending_closures10032026/09/10 17:37:11 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10042026/09/10 17:37:11 WARN Found objects in DB but missing from S3, will re-upload count=11005--- PASS: TestService_verifyS3Integrity (2.95s)1006=== CONT TestClientCADerivations10072026/09/10 17:37:11 OK 20241026095416_initial_model.sql (86.18ms)10082026/09/10 17:37:11 OK 20251210153512_drop_unused_gin_index.sql (6.99ms)10092026/09/10 17:37:11 OK 20251218171726_add_pins.sql (22.96ms)10102026/09/10 17:37:11 OK 20260628120000_add_object_size_and_stats.sql (23.42ms)10112026-09-10 17:37:11.328 UTC [99674] ERROR: relation "goose_db_version" does not exist at character 3610122026-09-10 17:37:11.328 UTC [99674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10132026/09/10 17:37:11 OK 20260905000000_add_claims.sql (33.62ms)10142026/09/10 17:37:11 goose: successfully migrated database to version: 2026090500000010152026/09/10 17:37:11 OK 1_commit_pending_closure.sql (6.44ms)10162026/09/10 17:37:11 OK 2_object_stats_trigger.sql (319.79µs)10172026/09/10 17:37:11 goose: up to current file version: 210182026/09/10 17:37:11 INFO Received uploads request method=POST path=/api/pending_closures10192026/09/10 17:37:11 OK 20241026095416_initial_model.sql (138.13ms)10202026/09/10 17:37:11 OK 20251210153512_drop_unused_gin_index.sql (71.56ms)10212026/09/10 17:37:11 OK 20251218171726_add_pins.sql (16.32ms)10222026/09/10 17:37:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10232026/09/10 17:37:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LjIwZjFjZTY5LWE1ODYtNGI1MC1hOGRiLWYzOTM4YjdmOGZlM3gxNzg5MDYxODMxNDAxNDc0MDAw10242026/09/10 17:37:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LjIwZjFjZTY5LWE1ODYtNGI1MC1hOGRiLWYzOTM4YjdmOGZlM3gxNzg5MDYxODMxNDAxNDc0MDAw parts=11025--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.98s)1026=== CONT TestService_healthCheckHandler10272026/09/10 17:37:11 OK 20260628120000_add_object_size_and_stats.sql (14.44ms)10282026/09/10 17:37:11 OK 20260905000000_add_claims.sql (34.55ms)10292026/09/10 17:37:11 goose: successfully migrated database to version: 2026090500000010302026/09/10 17:37:11 OK 1_commit_pending_closure.sql (5.3ms)10312026/09/10 17:37:11 OK 2_object_stats_trigger.sql (303.25µs)10322026/09/10 17:37:11 goose: up to current file version: 210332026/09/10 17:37:11 INFO Received uploads request method=POST path=/api/pending_closures10342026-09-10 17:37:11.722 UTC [99679] ERROR: relation "goose_db_version" does not exist at character 3610352026-09-10 17:37:11.722 UTC [99679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10362026/09/10 17:37:11 INFO Received uploads request method=POST path=/api/pending_closures10372026-09-10 17:37:11.778 UTC [99681] ERROR: relation "goose_db_version" does not exist at character 3610382026-09-10 17:37:11.778 UTC [99681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10392026-09-10 17:37:11.795 UTC [99684] ERROR: relation "goose_db_version" does not exist at character 3610402026-09-10 17:37:11.795 UTC [99684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10412026/09/10 17:37:11 OK 20241026095416_initial_model.sql (77.43ms)10422026/09/10 17:37:11 OK 20251210153512_drop_unused_gin_index.sql (9.98ms)10432026/09/10 17:37:11 OK 20251218171726_add_pins.sql (6.61ms)10442026/09/10 17:37:11 OK 20260628120000_add_object_size_and_stats.sql (21.02ms)10452026/09/10 17:37:11 OK 20241026095416_initial_model.sql (92.46ms)10462026/09/10 17:37:11 OK 20260905000000_add_claims.sql (25.32ms)10472026/09/10 17:37:11 goose: successfully migrated database to version: 2026090500000010482026/09/10 17:37:11 OK 1_commit_pending_closure.sql (6.81ms)10492026/09/10 17:37:11 OK 2_object_stats_trigger.sql (488.46µs)10502026/09/10 17:37:11 goose: up to current file version: 210512026/09/10 17:37:11 OK 20251210153512_drop_unused_gin_index.sql (11.56ms)10522026/09/10 17:37:11 OK 20251218171726_add_pins.sql (24.24ms)10532026/09/10 17:37:11 OK 20241026095416_initial_model.sql (117.27ms)10542026/09/10 17:37:11 OK 20251210153512_drop_unused_gin_index.sql (16.05ms)1055--- PASS: TestReadRedirectUsesPublicS3URL (1.87s)1056=== CONT TestClaim_StreamsThroughServer10572026/09/10 17:37:12 OK 20260628120000_add_object_size_and_stats.sql (54.69ms)10582026/09/10 17:37:12 OK 20251218171726_add_pins.sql (41.63ms)10592026/09/10 17:37:12 OK 20260905000000_add_claims.sql (16.99ms)10602026/09/10 17:37:12 goose: successfully migrated database to version: 2026090500000010612026/09/10 17:37:12 OK 20260628120000_add_object_size_and_stats.sql (9.01ms)10622026/09/10 17:37:12 OK 1_commit_pending_closure.sql (2.28ms)10632026/09/10 17:37:12 OK 2_object_stats_trigger.sql (724.96µs)10642026/09/10 17:37:12 goose: up to current file version: 210652026/09/10 17:37:12 OK 20260905000000_add_claims.sql (14.04ms)10662026/09/10 17:37:12 goose: successfully migrated database to version: 2026090500000010672026/09/10 17:37:12 OK 1_commit_pending_closure.sql (11.49ms)10682026/09/10 17:37:12 OK 2_object_stats_trigger.sql (247.04µs)10692026/09/10 17:37:12 goose: up to current file version: 210702026-09-10 17:37:12.193 UTC [99692] ERROR: relation "goose_db_version" does not exist at character 3610712026-09-10 17:37:12.193 UTC [99692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1072--- PASS: TestReadProxyInvalidPath (1.82s)1073=== CONT TestGracefulShutdownDrainsInflight10742026/09/10 17:37:12 INFO Starting HTTP server address=127.0.0.1:5003510752026/09/10 17:37:12 INFO Shutdown signal received, draining in-flight requests timeout=10s1076--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1077=== CONT TestClaim_InputsTouched10782026/09/10 17:37:12 OK 20241026095416_initial_model.sql (92.4ms)10792026/09/10 17:37:12 OK 20251210153512_drop_unused_gin_index.sql (7.08ms)10802026/09/10 17:37:12 OK 20251218171726_add_pins.sql (8.67ms)10812026/09/10 17:37:12 OK 20260628120000_add_object_size_and_stats.sql (33.82ms)10822026/09/10 17:37:12 OK 20260905000000_add_claims.sql (58.38ms)10832026/09/10 17:37:12 goose: successfully migrated database to version: 2026090500000010842026/09/10 17:37:12 OK 1_commit_pending_closure.sql (6.59ms)10852026/09/10 17:37:12 OK 2_object_stats_trigger.sql (258.13µs)10862026/09/10 17:37:12 goose: up to current file version: 21087--- PASS: TestReadProxyDisabled (1.69s)1088=== CONT TestGCTaskStore_Fail1089--- PASS: TestGCTaskStore_Fail (0.00s)1090=== CONT TestClaim_TwoInstances10912026/09/10 17:37:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10922026/09/10 17:37:12 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LjEyZWMzNDQ0LWZkOGUtNGI4Yi1hMjA3LWFlMzAwNzczNDRkYngxNzg5MDYxODMxMTg5NTE1MDAw parts=1210932026/09/10 17:37:12 INFO Received uploads request method=POST path=/api/pending_closures1094--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.10s)1095=== CONT TestGCTaskStore_PhaseUpdates1096--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1097=== CONT TestClaim_StaleHeartbeatStolen10982026/09/10 17:37:12 WARN readiness check failed error="closed pool"1099--- PASS: TestService_readinessHandler (2.14s)1100=== CONT TestGCTaskStore_CompletedAllowsNewTask1101--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1102=== CONT TestGCTaskStore_GetReturnsLatest1103--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1104=== CONT TestGCTaskStore_GetEmpty1105--- PASS: TestGCTaskStore_GetEmpty (0.00s)1106=== CONT TestOrphanedObjectsGC11072026-09-10 17:37:12.814 UTC [99710] ERROR: relation "goose_db_version" does not exist at character 3611082026-09-10 17:37:12.814 UTC [99710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11092026/09/10 17:37:12 OK 20241026095416_initial_model.sql (52.85ms)1110--- PASS: TestReadRedirectNar (1.96s)1111=== CONT TestGCTaskStore_ConflictDifferentParams1112--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1113=== CONT TestIsValidCachePath1114=== RUN TestIsValidCachePath/narinfo1115=== PAUSE TestIsValidCachePath/narinfo1116=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1117=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1118=== RUN TestIsValidCachePath/nar_zst1119=== PAUSE TestIsValidCachePath/nar_zst1120=== RUN TestIsValidCachePath/nar_xz1121=== PAUSE TestIsValidCachePath/nar_xz1122=== RUN TestIsValidCachePath/nar_bz21123=== PAUSE TestIsValidCachePath/nar_bz21124=== RUN TestIsValidCachePath/nar_uncompressed1125=== PAUSE TestIsValidCachePath/nar_uncompressed1126=== RUN TestIsValidCachePath/ls1127=== PAUSE TestIsValidCachePath/ls1128=== RUN TestIsValidCachePath/log1129=== PAUSE TestIsValidCachePath/log1130=== RUN TestIsValidCachePath/realisation1131=== PAUSE TestIsValidCachePath/realisation1132=== RUN TestIsValidCachePath/nix-cache-info1133=== PAUSE TestIsValidCachePath/nix-cache-info1134=== RUN TestIsValidCachePath/index.html1135=== PAUSE TestIsValidCachePath/index.html1136=== RUN TestIsValidCachePath/traversal_parent1137=== PAUSE TestIsValidCachePath/traversal_parent1138=== RUN TestIsValidCachePath/traversal_in_middle1139=== PAUSE TestIsValidCachePath/traversal_in_middle1140=== RUN TestIsValidCachePath/invalid_char_e1141=== PAUSE TestIsValidCachePath/invalid_char_e1142=== RUN TestIsValidCachePath/invalid_char_u1143=== PAUSE TestIsValidCachePath/invalid_char_u1144=== RUN TestIsValidCachePath/random_path1145=== PAUSE TestIsValidCachePath/random_path1146=== RUN TestIsValidCachePath/empty1147=== PAUSE TestIsValidCachePath/empty1148=== RUN TestIsValidCachePath/leading_slash1149=== PAUSE TestIsValidCachePath/leading_slash1150=== RUN TestIsValidCachePath/wrong_extension1151=== PAUSE TestIsValidCachePath/wrong_extension1152=== RUN TestIsValidCachePath/short_hash1153=== PAUSE TestIsValidCachePath/short_hash1154=== CONT TestClaim_FailWithoutKindReleases11552026/09/10 17:37:12 OK 20251210153512_drop_unused_gin_index.sql (8.23ms)11562026/09/10 17:37:12 OK 20251218171726_add_pins.sql (28.89ms)11572026/09/10 17:37:13 OK 20260628120000_add_object_size_and_stats.sql (30.02ms)11582026/09/10 17:37:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11592026/09/10 17:37:13 OK 20260905000000_add_claims.sql (76.33ms)11602026/09/10 17:37:13 goose: successfully migrated database to version: 2026090500000011612026/09/10 17:37:13 OK 1_commit_pending_closure.sql (1.12ms)11622026/09/10 17:37:13 OK 2_object_stats_trigger.sql (263.46µs)11632026/09/10 17:37:13 goose: up to current file version: 211642026/09/10 17:37:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LmQyZDRkNGExLWQ5NmYtNDhjNy04ZjFkLTEwNmE1OTYzOWFiOHgxNzg5MDYxODMxNzEwMjQ2MDAw parts=121165--- PASS: TestRedundantMultipartUpload (3.24s)1166=== CONT TestGCTaskStore_DeduplicateSameParams1167--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1168=== CONT TestParseSingleRange1169=== RUN TestParseSingleRange/none1170=== PAUSE TestParseSingleRange/none1171=== RUN TestParseSingleRange/unknown_unit1172=== PAUSE TestParseSingleRange/unknown_unit1173=== RUN TestParseSingleRange/multi-range_ignored1174=== PAUSE TestParseSingleRange/multi-range_ignored1175=== RUN TestParseSingleRange/malformed_no_dash1176=== PAUSE TestParseSingleRange/malformed_no_dash1177=== RUN TestParseSingleRange/malformed_both_empty1178=== PAUSE TestParseSingleRange/malformed_both_empty1179=== RUN TestParseSingleRange/malformed_end_before_start1180=== PAUSE TestParseSingleRange/malformed_end_before_start1181=== RUN TestParseSingleRange/closed1182=== PAUSE TestParseSingleRange/closed1183=== RUN TestParseSingleRange/open-ended1184=== PAUSE TestParseSingleRange/open-ended1185=== RUN TestParseSingleRange/end_clamped_to_size1186=== PAUSE TestParseSingleRange/end_clamped_to_size1187=== RUN TestParseSingleRange/suffix1188=== PAUSE TestParseSingleRange/suffix1189=== RUN TestParseSingleRange/suffix_exceeds_size1190=== PAUSE TestParseSingleRange/suffix_exceeds_size1191=== RUN TestParseSingleRange/single_byte1192=== PAUSE TestParseSingleRange/single_byte1193=== RUN TestParseSingleRange/start_past_EOF1194=== PAUSE TestParseSingleRange/start_past_EOF1195=== RUN TestParseSingleRange/start_far_past_EOF1196=== PAUSE TestParseSingleRange/start_far_past_EOF1197=== CONT TestClaim_FailWakesWaitersButIsNotRemembered11982026/09/10 17:37:13 WARN Rate limiter enabled after throttle name=s3-test rate=511992026/09/10 17:37:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1200=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1201 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101202 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001203--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.32s)1204=== CONT TestGCTaskStore_StartNew1205--- PASS: TestGCTaskStore_StartNew (0.00s)1206=== CONT TestResurrectedObjectNotDeleted12072026-09-10 17:37:13.218 UTC [99763] ERROR: relation "goose_db_version" does not exist at character 3612082026-09-10 17:37:13.218 UTC [99763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12092026/09/10 17:37:13 OK 20241026095416_initial_model.sql (65.63ms)12102026/09/10 17:37:13 OK 20251210153512_drop_unused_gin_index.sql (11.27ms)12112026/09/10 17:37:13 OK 20251218171726_add_pins.sql (14.69ms)1212--- PASS: TestService_healthCheckHandler (1.76s)1213=== CONT TestGCMetrics12142026/09/10 17:37:13 OK 20260628120000_add_object_size_and_stats.sql (25.54ms)12152026/09/10 17:37:13 OK 20260905000000_add_claims.sql (12.19ms)12162026/09/10 17:37:13 goose: successfully migrated database to version: 2026090500000012172026-09-10 17:37:13.375 UTC [99774] ERROR: relation "goose_db_version" does not exist at character 3612182026-09-10 17:37:13.375 UTC [99774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12192026/09/10 17:37:13 OK 1_commit_pending_closure.sql (2.18ms)12202026/09/10 17:37:13 OK 2_object_stats_trigger.sql (318.25µs)12212026/09/10 17:37:13 goose: up to current file version: 212222026/09/10 17:37:13 OK 20241026095416_initial_model.sql (58.86ms)12232026/09/10 17:37:13 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)12242026/09/10 17:37:13 OK 20251218171726_add_pins.sql (19.17ms)1225=== NAME TestClientCADerivations1226 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-99207-761247270/TestClientCADerivations3922971714/001/store/5q68mpvnz5fz4fm09vi76vkf2h600syj-ca-test12272026/09/10 17:37:13 OK 20260628120000_add_object_size_and_stats.sql (16.22ms)12282026/09/10 17:37:13 OK 20260905000000_add_claims.sql (21.99ms)12292026/09/10 17:37:13 goose: successfully migrated database to version: 2026090500000012302026/09/10 17:37:13 OK 1_commit_pending_closure.sql (2.39ms)12312026/09/10 17:37:13 OK 2_object_stats_trigger.sql (635.63µs)12322026/09/10 17:37:13 goose: up to current file version: 21233 client_ca_test.go:139: Found 1 dependencies (including self)12342026-09-10 17:37:13.577 UTC [99779] ERROR: relation "goose_db_version" does not exist at character 3612352026-09-10 17:37:13.577 UTC [99779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026-09-10 17:37:13.614 UTC [99782] ERROR: relation "goose_db_version" does not exist at character 3612372026-09-10 17:37:13.614 UTC [99782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12382026/09/10 17:37:13 OK 20241026095416_initial_model.sql (40.99ms)12392026/09/10 17:37:13 OK 20251210153512_drop_unused_gin_index.sql (5.33ms)12402026/09/10 17:37:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12412026/09/10 17:37:13 OK 20251218171726_add_pins.sql (20.9ms)12422026/09/10 17:37:13 OK 20260628120000_add_object_size_and_stats.sql (25.7ms)12432026/09/10 17:37:13 INFO Received uploads request method=POST path=/api/pending_closures12442026/09/10 17:37:13 OK 20260905000000_add_claims.sql (1.91ms)12452026/09/10 17:37:13 goose: successfully migrated database to version: 2026090500000012462026/09/10 17:37:13 INFO Received uploads request method=POST path=/api/pending_closures12472026/09/10 17:37:13 OK 1_commit_pending_closure.sql (1.28ms)12482026/09/10 17:37:13 OK 2_object_stats_trigger.sql (315.46µs)12492026/09/10 17:37:13 goose: up to current file version: 212502026/09/10 17:37:13 OK 20241026095416_initial_model.sql (67.95ms)12512026/09/10 17:37:13 OK 20251210153512_drop_unused_gin_index.sql (556.67µs)12522026/09/10 17:37:13 OK 20251218171726_add_pins.sql (18.19ms)12532026/09/10 17:37:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12542026/09/10 17:37:13 INFO Uploading 5q68mpvnz5fz4fm09vi76vkf2h600syj-ca-test (144B)12552026/09/10 17:37:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12562026/09/10 17:37:13 WARN Failed to register uploaded object key=log/s9gaxhdgz7mqdgy2l6qxavy95cnfv4mw-ca-test.drv error="server returned 404: 404 page not found\n"12572026/09/10 17:37:13 OK 20260628120000_add_object_size_and_stats.sql (28.32ms)12582026/09/10 17:37:13 WARN Failed to register uploaded object key=5q68mpvnz5fz4fm09vi76vkf2h600syj.ls error="server returned 404: 404 page not found\n"12592026/09/10 17:37:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12602026/09/10 17:37:13 INFO Signed narinfos id=1 count=112612026/09/10 17:37:13 INFO Uploading 1 narinfos12622026/09/10 17:37:13 WARN Failed to register uploaded object key=5q68mpvnz5fz4fm09vi76vkf2h600syj.narinfo error="server returned 404: 404 page not found\n"12632026/09/10 17:37:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12642026/09/10 17:37:13 OK 20260905000000_add_claims.sql (18.96ms)12652026/09/10 17:37:13 goose: successfully migrated database to version: 2026090500000012662026/09/10 17:37:13 OK 1_commit_pending_closure.sql (7.64ms)12672026/09/10 17:37:13 OK 2_object_stats_trigger.sql (200.38µs)12682026/09/10 17:37:13 goose: up to current file version: 212692026/09/10 17:37:13 INFO Completed upload id=112702026/09/10 17:37:13 INFO Upload complete. (183ms)1271 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-99207-761247270/TestClientCADerivations3922971714/001/store/5q68mpvnz5fz4fm09vi76vkf2h600syj-ca-test1272 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1273 Compression: zstd1274 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1275 NarSize: 1441276 References: 1277 Deriver: /nix/var/nix/builds/nix-99207-761247270/TestClientCADerivations3922971714/001/store/s9gaxhdgz7mqdgy2l6qxavy95cnfv4mw-ca-test.drv1278 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1279 client_ca_test.go:185: Checking for realisation files in S3...1280 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1281 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache12822026-09-10 17:37:13.811 UTC [99789] ERROR: relation "goose_db_version" does not exist at character 3612832026-09-10 17:37:13.811 UTC [99789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12842026/09/10 17:37:13 WARN claim: cannot clear write deadline error="feature not supported"12852026/09/10 17:37:13 WARN claim: cannot clear write deadline error="feature not supported"12862026/09/10 17:37:13 WARN claim: cannot clear write deadline error="feature not supported"12872026/09/10 17:37:13 INFO Received uploads request method=POST path=/api/pending_closures1288 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket24?endpoint=http://localhost:49948®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-99207-761247270/TestClientCADerivations3922971714/001/store'1289 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11290--- PASS: TestClientCADerivations (2.81s)1291=== CONT TestOrphanedObjectsGCStressTest12922026/09/10 17:37:14 OK 20241026095416_initial_model.sql (207.62ms)12932026/09/10 17:37:14 OK 20251210153512_drop_unused_gin_index.sql (7.86ms)12942026/09/10 17:37:14 OK 20251218171726_add_pins.sql (25.81ms)12952026/09/10 17:37:14 WARN claim: cannot clear write deadline error="feature not supported"12962026/09/10 17:37:14 OK 20260628120000_add_object_size_and_stats.sql (115.39ms)12972026/09/10 17:37:14 WARN claim: cannot clear write deadline error="feature not supported"1298--- PASS: TestClaim_StaleHeartbeatStolen (1.66s)1299=== CONT TestGCBugBareHashReferences13002026/09/10 17:37:14 OK 20260905000000_add_claims.sql (17.64ms)13012026/09/10 17:37:14 goose: successfully migrated database to version: 2026090500000013022026/09/10 17:37:14 OK 1_commit_pending_closure.sql (3.66ms)13032026/09/10 17:37:14 OK 2_object_stats_trigger.sql (563.71µs)13042026/09/10 17:37:14 goose: up to current file version: 213052026-09-10 17:37:14.641 UTC [99801] ERROR: relation "goose_db_version" does not exist at character 3613062026-09-10 17:37:14.641 UTC [99801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13072026-09-10 17:37:14.664 UTC [99802] ERROR: relation "goose_db_version" does not exist at character 3613082026-09-10 17:37:14.664 UTC [99802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13092026-09-10 17:37:14.836 UTC [99803] ERROR: relation "goose_db_version" does not exist at character 3613102026-09-10 17:37:14.836 UTC [99803] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13112026/09/10 17:37:14 OK 20241026095416_initial_model.sql (140.6ms)13122026/09/10 17:37:14 OK 20241026095416_initial_model.sql (158.23ms)13132026/09/10 17:37:14 OK 20251210153512_drop_unused_gin_index.sql (6.88ms)13142026/09/10 17:37:14 OK 20251210153512_drop_unused_gin_index.sql (15.77ms)13152026/09/10 17:37:14 OK 20251218171726_add_pins.sql (40.21ms)13162026/09/10 17:37:14 OK 20251218171726_add_pins.sql (39.18ms)13172026/09/10 17:37:14 OK 20260628120000_add_object_size_and_stats.sql (33.86ms)13182026/09/10 17:37:14 OK 20260628120000_add_object_size_and_stats.sql (33.78ms)13192026/09/10 17:37:15 OK 20260905000000_add_claims.sql (57.7ms)13202026/09/10 17:37:15 goose: successfully migrated database to version: 2026090500000013212026/09/10 17:37:15 OK 20260905000000_add_claims.sql (64.46ms)13222026/09/10 17:37:15 goose: successfully migrated database to version: 2026090500000013232026/09/10 17:37:15 OK 1_commit_pending_closure.sql (9.37ms)13242026/09/10 17:37:15 OK 2_object_stats_trigger.sql (880.54µs)13252026/09/10 17:37:15 goose: up to current file version: 213262026/09/10 17:37:15 OK 1_commit_pending_closure.sql (10.92ms)13272026/09/10 17:37:15 OK 2_object_stats_trigger.sql (560.38µs)13282026/09/10 17:37:15 goose: up to current file version: 21329--- PASS: TestClaim_StreamsThroughServer (3.05s)1330=== CONT TestClaim_HolderDisconnectKeepsClaim13312026/09/10 17:37:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13322026/09/10 17:37:15 OK 20241026095416_initial_model.sql (216.96ms)13332026/09/10 17:37:15 OK 20251210153512_drop_unused_gin_index.sql (32.5ms)13342026/09/10 17:37:15 OK 20251218171726_add_pins.sql (25.27ms)13352026/09/10 17:37:15 OK 20260628120000_add_object_size_and_stats.sql (10.18ms)13362026/09/10 17:37:15 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LmNkZTE5NWYyLTU0YzUtNDA1Ny05ZjdjLTIwY2I2ZTkzZTFlZngxNzg5MDYxODMzNzIyOTc0MDAw parts=1013372026/09/10 17:37:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13382026/09/10 17:37:15 INFO Completed upload id=113392026/09/10 17:37:15 WARN claim: cannot clear write deadline error="feature not supported"13402026-09-10 17:37:15.191 UTC [99806] ERROR: relation "goose_db_version" does not exist at character 3613412026-09-10 17:37:15.191 UTC [99806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13422026/09/10 17:37:15 INFO Aborted multipart uploads count=013432026/09/10 17:37:15 WARN Force mode enabled - objects will be deleted immediately without grace period13442026/09/10 17:37:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013452026/09/10 17:37:15 INFO Vacuumed table table=pending_closures13462026/09/10 17:37:15 OK 20260905000000_add_claims.sql (41.81ms)13472026/09/10 17:37:15 goose: successfully migrated database to version: 2026090500000013482026/09/10 17:37:15 OK 1_commit_pending_closure.sql (7.98ms)13492026/09/10 17:37:15 OK 2_object_stats_trigger.sql (368.29µs)13502026/09/10 17:37:15 goose: up to current file version: 213512026/09/10 17:37:15 INFO Vacuumed table table=pending_objects13522026/09/10 17:37:15 INFO Vacuumed table table=multipart_uploads13532026/09/10 17:37:15 INFO Vacuumed table table=closures13542026/09/10 17:37:15 INFO Vacuumed table table=objects1355--- PASS: TestClaim_InputsTouched (3.05s)1356=== CONT TestReadProxyRootRedirectsToIndexHTML13572026/09/10 17:37:15 WARN claim: cannot clear write deadline error="feature not supported"13582026/09/10 17:37:15 WARN claim: cannot clear write deadline error="feature not supported"1359--- PASS: TestClaim_FailWithoutKindReleases (2.42s)1360=== CONT TestClaim_TooManyStreams1361=== NAME TestOrphanedObjectsGC1362 orphaned_objects_gc_test.go:290: GC Test Summary:1363 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1364 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1365 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1366 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1367 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1368--- PASS: TestOrphanedObjectsGC (2.69s)1369=== CONT TestService_RequireScope_OIDC13702026/09/10 17:37:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50084/oidc13712026/09/10 17:37:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13722026/09/10 17:37:15 OK 20241026095416_initial_model.sql (178.91ms)13732026/09/10 17:37:15 OK 20251210153512_drop_unused_gin_index.sql (35.85ms)13742026/09/10 17:37:15 OK 20251218171726_add_pins.sql (24.38ms)13752026/09/10 17:37:15 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LjY4NTY4YmEzLWQwZmQtNDY5Mi04NWJkLTk5ZGFkMzVlYWNmZngxNzg5MDYxODMzOTI3NDU2MDAw parts=1013762026/09/10 17:37:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13772026/09/10 17:37:15 INFO Signed narinfos id=1 count=113782026/09/10 17:37:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13792026/09/10 17:37:15 INFO Completed upload id=11380--- PASS: TestClaim_TwoInstances (3.09s)1381=== CONT TestService_ReadScope_PublicByDefault13822026/09/10 17:37:15 OK 20260628120000_add_object_size_and_stats.sql (29.8ms)13832026/09/10 17:37:15 OK 20260905000000_add_claims.sql (49.89ms)13842026/09/10 17:37:15 goose: successfully migrated database to version: 2026090500000013852026/09/10 17:37:15 OK 1_commit_pending_closure.sql (2.33ms)13862026/09/10 17:37:15 OK 2_object_stats_trigger.sql (473.29µs)13872026/09/10 17:37:15 goose: up to current file version: 213882026/09/10 17:37:15 WARN claim: cannot clear write deadline error="feature not supported"13892026/09/10 17:37:15 WARN claim: cannot clear write deadline error="feature not supported"13902026/09/10 17:37:15 WARN claim: cannot clear write deadline error="feature not supported"1391--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (2.56s)1392=== CONT TestClaim_GCMarkedOutputCountsAsAbsent13932026-09-10 17:37:16.081 UTC [99821] ERROR: relation "goose_db_version" does not exist at character 3613942026-09-10 17:37:16.081 UTC [99821] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1395--- PASS: TestResurrectedObjectNotDeleted (2.94s)1396=== CONT TestClaim_BuildWaitComplete13972026/09/10 17:37:16 INFO Aborted multipart uploads count=013982026/09/10 17:37:16 WARN Force mode enabled - objects will be deleted immediately without grace period13992026/09/10 17:37:16 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=014002026/09/10 17:37:16 INFO Vacuumed table table=pending_closures14012026/09/10 17:37:16 INFO Vacuumed table table=pending_objects14022026/09/10 17:37:16 INFO Vacuumed table table=multipart_uploads14032026/09/10 17:37:16 INFO Vacuumed table table=closures14042026/09/10 17:37:16 INFO Vacuumed table table=objects1405--- PASS: TestGCMetrics (2.92s)1406=== CONT TestCacheStatsHandler14072026/09/10 17:37:16 OK 20241026095416_initial_model.sql (209.95ms)14082026/09/10 17:37:16 OK 20251210153512_drop_unused_gin_index.sql (7.91ms)14092026-09-10 17:37:16.351 UTC [99826] ERROR: relation "goose_db_version" does not exist at character 3614102026-09-10 17:37:16.351 UTC [99826] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14112026/09/10 17:37:16 OK 20251218171726_add_pins.sql (4.4ms)14122026/09/10 17:37:16 OK 20260628120000_add_object_size_and_stats.sql (39.96ms)14132026/09/10 17:37:16 OK 20260905000000_add_claims.sql (29.01ms)14142026/09/10 17:37:16 goose: successfully migrated database to version: 2026090500000014152026/09/10 17:37:16 OK 1_commit_pending_closure.sql (3.45ms)14162026/09/10 17:37:16 OK 2_object_stats_trigger.sql (501.63µs)14172026/09/10 17:37:16 goose: up to current file version: 214182026/09/10 17:37:16 OK 20241026095416_initial_model.sql (152.25ms)14192026/09/10 17:37:16 OK 20251210153512_drop_unused_gin_index.sql (9.96ms)14202026/09/10 17:37:16 OK 20251218171726_add_pins.sql (48.43ms)14212026/09/10 17:37:16 OK 20260628120000_add_object_size_and_stats.sql (31.53ms)14222026/09/10 17:37:16 OK 20260905000000_add_claims.sql (25.93ms)14232026/09/10 17:37:16 goose: successfully migrated database to version: 2026090500000014242026/09/10 17:37:16 OK 1_commit_pending_closure.sql (3.85ms)14252026/09/10 17:37:16 OK 2_object_stats_trigger.sql (667.54µs)14262026/09/10 17:37:16 goose: up to current file version: 214272026-09-10 17:37:16.820 UTC [99828] ERROR: relation "goose_db_version" does not exist at character 3614282026-09-10 17:37:16.820 UTC [99828] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14292026/09/10 17:37:17 OK 20241026095416_initial_model.sql (195.76ms)14302026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (9.56ms)14312026/09/10 17:37:17 OK 20251218171726_add_pins.sql (22.41ms)14322026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (28.31ms)14332026-09-10 17:37:17.171 UTC [99829] ERROR: relation "goose_db_version" does not exist at character 3614342026-09-10 17:37:17.171 UTC [99829] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14352026-09-10 17:37:17.171 UTC [99830] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-10 17:37:17.171 UTC [99830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026-09-10 17:37:17.171 UTC [99831] ERROR: relation "goose_db_version" does not exist at character 3614382026-09-10 17:37:17.171 UTC [99831] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026/09/10 17:37:17 OK 20260905000000_add_claims.sql (35.58ms)14402026/09/10 17:37:17 goose: successfully migrated database to version: 2026090500000014412026/09/10 17:37:17 OK 1_commit_pending_closure.sql (11.49ms)14422026/09/10 17:37:17 OK 2_object_stats_trigger.sql (2.64ms)14432026/09/10 17:37:17 goose: up to current file version: 214442026-09-10 17:37:17.240 UTC [99832] ERROR: relation "goose_db_version" does not exist at character 3614452026-09-10 17:37:17.240 UTC [99832] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14462026/09/10 17:37:17 OK 20241026095416_initial_model.sql (70.87ms)14472026/09/10 17:37:17 OK 20241026095416_initial_model.sql (87.03ms)14482026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (16.2ms)14492026/09/10 17:37:17 OK 20241026095416_initial_model.sql (93.91ms)14502026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (15.05ms)14512026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (8.23ms)1452--- PASS: TestGCBugBareHashReferences (3.07s)1453=== CONT TestCacheConfigHandler1454=== RUN TestCacheConfigHandler/full_config,_no_issuer1455=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1456=== RUN TestCacheConfigHandler/no_cache_url_configured1457=== PAUSE TestCacheConfigHandler/no_cache_url_configured1458=== RUN TestCacheConfigHandler/no_signing_keys1459=== PAUSE TestCacheConfigHandler/no_signing_keys1460=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1461=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1462=== CONT TestServerTLSConfig1463=== RUN TestServerTLSConfig/no_client_CA1464=== PAUSE TestServerTLSConfig/no_client_CA1465=== RUN TestServerTLSConfig/missing_CA_file1466=== PAUSE TestServerTLSConfig/missing_CA_file1467=== RUN TestServerTLSConfig/not_a_PEM_file1468=== PAUSE TestServerTLSConfig/not_a_PEM_file1469=== CONT TestObjectStatsTrigger14702026/09/10 17:37:17 OK 20251218171726_add_pins.sql (27.41ms)14712026/09/10 17:37:17 OK 20251218171726_add_pins.sql (42.72ms)14722026/09/10 17:37:17 OK 20251218171726_add_pins.sql (27.89ms)14732026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (30.24ms)14742026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (30.42ms)14752026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (30.93ms)14762026-09-10 17:37:17.385 UTC [99834] ERROR: relation "goose_db_version" does not exist at character 3614772026-09-10 17:37:17.385 UTC [99834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14782026/09/10 17:37:17 OK 20260905000000_add_claims.sql (47.23ms)14792026/09/10 17:37:17 goose: successfully migrated database to version: 2026090500000014802026/09/10 17:37:17 OK 20260905000000_add_claims.sql (48.96ms)14812026/09/10 17:37:17 goose: successfully migrated database to version: 2026090500000014822026/09/10 17:37:17 OK 20260905000000_add_claims.sql (49.33ms)14832026/09/10 17:37:17 goose: successfully migrated database to version: 2026090500000014842026/09/10 17:37:17 OK 1_commit_pending_closure.sql (4.44ms)14852026/09/10 17:37:17 OK 2_object_stats_trigger.sql (709.42µs)14862026/09/10 17:37:17 goose: up to current file version: 214872026/09/10 17:37:17 OK 1_commit_pending_closure.sql (9.6ms)14882026/09/10 17:37:17 OK 1_commit_pending_closure.sql (9.67ms)14892026/09/10 17:37:17 OK 2_object_stats_trigger.sql (597.67µs)14902026/09/10 17:37:17 goose: up to current file version: 214912026/09/10 17:37:17 OK 2_object_stats_trigger.sql (606.88µs)14922026/09/10 17:37:17 goose: up to current file version: 214932026/09/10 17:37:17 OK 20241026095416_initial_model.sql (180.16ms)14942026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (5.86ms)14952026/09/10 17:37:17 WARN claim: cannot clear write deadline error="feature not supported"14962026/09/10 17:37:17 OK 20251218171726_add_pins.sql (27.86ms)14972026/09/10 17:37:17 WARN claim: cannot clear write deadline error="feature not supported"14982026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (51.74ms)14992026/09/10 17:37:17 OK 20260905000000_add_claims.sql (68.1ms)15002026/09/10 17:37:17 goose: successfully migrated database to version: 2026090500000015012026/09/10 17:37:17 OK 1_commit_pending_closure.sql (6.15ms)15022026/09/10 17:37:17 OK 2_object_stats_trigger.sql (994.29µs)15032026/09/10 17:37:17 goose: up to current file version: 215042026/09/10 17:37:17 OK 20241026095416_initial_model.sql (184.43ms)15052026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (8.51ms)15062026/09/10 17:37:17 OK 20251218171726_add_pins.sql (19.52ms)15072026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (31.22ms)15082026/09/10 17:37:17 OK 20260905000000_add_claims.sql (50.92ms)15092026/09/10 17:37:17 goose: successfully migrated database to version: 2026090500000015102026/09/10 17:37:17 OK 1_commit_pending_closure.sql (6.13ms)15112026/09/10 17:37:17 OK 2_object_stats_trigger.sql (1.68ms)15122026/09/10 17:37:17 goose: up to current file version: 215132026-09-10 17:37:17.807 UTC [99837] ERROR: relation "goose_db_version" does not exist at character 3615142026-09-10 17:37:17.807 UTC [99837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1515=== RUN TestService_RequireScope_OIDC/builder_may_write1516=== PAUSE TestService_RequireScope_OIDC/builder_may_write1517=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1518=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1519=== RUN TestService_RequireScope_OIDC/ops_may_admin1520=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1521=== RUN TestService_RequireScope_OIDC/ops_may_not_write1522=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1523=== RUN TestService_RequireScope_OIDC/reader_may_not_write1524=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1525=== RUN TestService_RequireScope_OIDC/static_token_may_admin1526=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1527=== RUN TestService_RequireScope_OIDC/static_token_may_write1528=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1529=== RUN TestService_RequireScope_OIDC/reader_may_read1530=== PAUSE TestService_RequireScope_OIDC/reader_may_read1531=== RUN TestService_RequireScope_OIDC/writer_implies_read1532=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1533=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1534=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1535=== CONT TestMultipartCleanup15362026-09-10 17:37:17.852 UTC [99839] ERROR: relation "goose_db_version" does not exist at character 3615372026-09-10 17:37:17.852 UTC [99839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15382026/09/10 17:37:17 OK 20241026095416_initial_model.sql (61.99ms)15392026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (7.69ms)15402026/09/10 17:37:17 OK 20251218171726_add_pins.sql (8.34ms)15412026/09/10 17:37:17 OK 20241026095416_initial_model.sql (69.65ms)15422026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (20.68ms)15432026/09/10 17:37:17 OK 20251210153512_drop_unused_gin_index.sql (8.13ms)15442026/09/10 17:37:17 OK 20251218171726_add_pins.sql (13.71ms)15452026/09/10 17:37:17 OK 20260905000000_add_claims.sql (32.97ms)15462026/09/10 17:37:17 goose: successfully migrated database to version: 2026090500000015472026/09/10 17:37:17 OK 1_commit_pending_closure.sql (7.34ms)15482026/09/10 17:37:17 OK 2_object_stats_trigger.sql (730.83µs)15492026/09/10 17:37:17 goose: up to current file version: 215502026/09/10 17:37:17 OK 20260628120000_add_object_size_and_stats.sql (28.97ms)15512026/09/10 17:37:17 WARN claim: cannot clear write deadline error="feature not supported"15522026/09/10 17:37:18 WARN claim: cannot clear write deadline error="feature not supported"15532026/09/10 17:37:18 OK 20260905000000_add_claims.sql (6.92ms)15542026/09/10 17:37:18 goose: successfully migrated database to version: 2026090500000015552026/09/10 17:37:18 OK 1_commit_pending_closure.sql (4.26ms)15562026/09/10 17:37:18 OK 2_object_stats_trigger.sql (1.09ms)15572026/09/10 17:37:18 goose: up to current file version: 21558--- PASS: TestClaim_TooManyStreams (2.63s)1559=== CONT TestReadProxyNarStreaming1560--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.85s)1561=== CONT TestReadProxyConditionalGet15622026-09-10 17:37:18.273 UTC [99853] ERROR: relation "goose_db_version" does not exist at character 3615632026-09-10 17:37:18.273 UTC [99853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1564--- PASS: TestService_ReadScope_PublicByDefault (2.84s)1565=== CONT TestResolveDBConnectionString1566=== RUN TestResolveDBConnectionString/flag_wins1567=== PAUSE TestResolveDBConnectionString/flag_wins1568=== RUN TestResolveDBConnectionString/file_when_flag_empty1569=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1570=== RUN TestResolveDBConnectionString/missing_file_is_an_error1571=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1572=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1573=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1574=== RUN TestResolveDBConnectionString/nothing_configured1575=== PAUSE TestResolveDBConnectionString/nothing_configured1576=== CONT TestService_AuthMiddleware_OIDC15772026/09/10 17:37:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50106/oidc15782026/09/10 17:37:18 OK 20241026095416_initial_model.sql (86.22ms)15792026/09/10 17:37:18 OK 20251210153512_drop_unused_gin_index.sql (4.81ms)15802026/09/10 17:37:18 OK 20251218171726_add_pins.sql (15.41ms)15812026/09/10 17:37:18 OK 20260628120000_add_object_size_and_stats.sql (15.92ms)15822026/09/10 17:37:18 OK 20260905000000_add_claims.sql (20.88ms)15832026/09/10 17:37:18 goose: successfully migrated database to version: 2026090500000015842026/09/10 17:37:18 OK 1_commit_pending_closure.sql (2.81ms)15852026/09/10 17:37:18 OK 2_object_stats_trigger.sql (434.63µs)15862026/09/10 17:37:18 goose: up to current file version: 215872026/09/10 17:37:18 INFO Received uploads request method=POST path=/api/pending_closures15882026-09-10 17:37:18.707 UTC [99857] ERROR: relation "goose_db_version" does not exist at character 3615892026-09-10 17:37:18.707 UTC [99857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15902026/09/10 17:37:18 WARN claim: cannot clear write deadline error="feature not supported"15912026/09/10 17:37:18 WARN claim: cannot clear write deadline error="feature not supported"15922026/09/10 17:37:18 WARN claim: cannot clear write deadline error="feature not supported"15932026/09/10 17:37:18 INFO Received uploads request method=POST path=/api/pending_closures15942026/09/10 17:37:18 OK 20241026095416_initial_model.sql (168.32ms)15952026/09/10 17:37:18 OK 20251210153512_drop_unused_gin_index.sql (3.87ms)15962026/09/10 17:37:18 OK 20251218171726_add_pins.sql (18.93ms)15972026/09/10 17:37:18 OK 20260628120000_add_object_size_and_stats.sql (48.5ms)15982026/09/10 17:37:19 OK 20260905000000_add_claims.sql (52.52ms)15992026/09/10 17:37:19 goose: successfully migrated database to version: 2026090500000016002026/09/10 17:37:19 OK 1_commit_pending_closure.sql (8.63ms)16012026/09/10 17:37:19 OK 2_object_stats_trigger.sql (681.83µs)16022026/09/10 17:37:19 goose: up to current file version: 216032026-09-10 17:37:19.171 UTC [99859] ERROR: relation "goose_db_version" does not exist at character 3616042026-09-10 17:37:19.171 UTC [99859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1605--- PASS: TestCacheStatsHandler (2.91s)1606=== CONT TestService_ReadAuthMiddleware16072026/09/10 17:37:19 OK 20241026095416_initial_model.sql (154.66ms)16082026/09/10 17:37:19 OK 20251210153512_drop_unused_gin_index.sql (14.61ms)16092026/09/10 17:37:19 OK 20251218171726_add_pins.sql (45.45ms)16102026/09/10 17:37:19 OK 20260628120000_add_object_size_and_stats.sql (19.06ms)16112026-09-10 17:37:19.474 UTC [99863] ERROR: relation "goose_db_version" does not exist at character 3616122026-09-10 17:37:19.474 UTC [99863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16132026/09/10 17:37:19 OK 20260905000000_add_claims.sql (28.81ms)16142026/09/10 17:37:19 goose: successfully migrated database to version: 2026090500000016152026/09/10 17:37:19 OK 1_commit_pending_closure.sql (9.21ms)16162026/09/10 17:37:19 OK 2_object_stats_trigger.sql (381.25µs)16172026/09/10 17:37:19 goose: up to current file version: 21618--- PASS: TestObjectStatsTrigger (2.19s)1619=== CONT TestClientIntegration16202026/09/10 17:37:19 INFO Received uploads request method=POST path=/api/pending_closures16212026/09/10 17:37:19 OK 20241026095416_initial_model.sql (182.68ms)16222026/09/10 17:37:19 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)16232026/09/10 17:37:19 OK 20251218171726_add_pins.sql (25.95ms)16242026/09/10 17:37:19 OK 20260628120000_add_object_size_and_stats.sql (47.73ms)16252026/09/10 17:37:19 OK 20260905000000_add_claims.sql (53.78ms)16262026/09/10 17:37:19 goose: successfully migrated database to version: 2026090500000016272026/09/10 17:37:19 OK 1_commit_pending_closure.sql (13.39ms)16282026/09/10 17:37:19 OK 2_object_stats_trigger.sql (2.84ms)16292026/09/10 17:37:19 goose: up to current file version: 216302026/09/10 17:37:19 INFO Received cleanup request method=DELETE path=/api/pending_closures16312026/09/10 17:37:19 INFO Aborted multipart uploads count=116322026-09-10 17:37:19.946 UTC [99866] ERROR: relation "goose_db_version" does not exist at character 3616332026-09-10 17:37:19.946 UTC [99866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1634--- PASS: TestMultipartCleanup (2.14s)1635=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16362026/09/10 17:37:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1637--- PASS: TestClaim_HolderDisconnectKeepsClaim (4.95s)1638=== CONT TestService_AuthMiddleware_MTLSProxyHeader16392026/09/10 17:37:20 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LjZlZGYyNzU0LWVhMTEtNGQwNS04YzBmLTk5MTkyZmYwYjhjYXgxNzg5MDYxODM4NjE5OTM1MDAw parts=1016402026/09/10 17:37:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16412026/09/10 17:37:20 INFO Completed upload id=116422026/09/10 17:37:20 WARN claim: cannot clear write deadline error="feature not supported"16432026/09/10 17:37:20 WARN claim: cannot clear write deadline error="feature not supported"1644--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (4.38s)1645=== CONT TestClientErrorHandling1646=== RUN TestClientErrorHandling/InvalidStorePath1647=== PAUSE TestClientErrorHandling/InvalidStorePath1648=== RUN TestClientErrorHandling/InvalidAuthToken1649=== PAUSE TestClientErrorHandling/InvalidAuthToken1650=== RUN TestClientErrorHandling/ServerNotAvailable1651=== PAUSE TestClientErrorHandling/ServerNotAvailable1652=== CONT TestReadProxyNarinfoAlreadyDecompressed1653--- PASS: TestReadProxyNarStreaming (2.07s)1654=== CONT TestService_NativeMTLS16552026/09/10 17:37:20 OK 20241026095416_initial_model.sql (115.77ms)16562026/09/10 17:37:20 OK 20251210153512_drop_unused_gin_index.sql (6.61ms)16572026/09/10 17:37:20 OK 20251218171726_add_pins.sql (9ms)16582026/09/10 17:37:20 OK 20260628120000_add_object_size_and_stats.sql (21.23ms)16592026/09/10 17:37:20 OK 20260905000000_add_claims.sql (44.64ms)16602026/09/10 17:37:20 goose: successfully migrated database to version: 2026090500000016612026/09/10 17:37:20 OK 1_commit_pending_closure.sql (2.57ms)16622026/09/10 17:37:20 OK 2_object_stats_trigger.sql (369.67µs)16632026/09/10 17:37:20 goose: up to current file version: 216642026/09/10 17:37:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16652026/09/10 17:37:20 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=M2I0OWE5NWUtYzdjNy00YTFhLTgxNWEtYWQxMTZlZDg5YWQ2LmVlOThjMTQzLTYxMTQtNGVjNi1hYTEzLTA3YTk5YmJhYTU2ZngxNzg5MDYxODM4ODg4MDQ2MDAw parts=1016662026/09/10 17:37:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16672026/09/10 17:37:20 INFO Signed narinfos id=1 count=116682026/09/10 17:37:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16692026/09/10 17:37:20 INFO Received uploads request method=POST path=/api/pending_closures16702026/09/10 17:37:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16712026/09/10 17:37:20 INFO Signed narinfos id=2 count=116722026/09/10 17:37:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1673--- PASS: TestReadProxyConditionalGet (2.15s)1674=== CONT TestPinProtectsFromGC16752026/09/10 17:37:20 INFO Completed upload id=216762026/09/10 17:37:20 WARN claim: cannot clear write deadline error="feature not supported"1677--- PASS: TestClaim_BuildWaitComplete (4.22s)1678=== CONT TestReadProxyRangeRequest1679=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1680=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1681=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1682=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1683=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1684=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1685=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1686=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1687=== CONT TestClientWithDependencies16882026-09-10 17:37:20.521 UTC [99880] ERROR: relation "goose_db_version" does not exist at character 3616892026-09-10 17:37:20.521 UTC [99880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16902026/09/10 17:37:20 OK 20241026095416_initial_model.sql (19.33ms)16912026/09/10 17:37:20 OK 20251210153512_drop_unused_gin_index.sql (784.42µs)16922026/09/10 17:37:20 OK 20251218171726_add_pins.sql (2.28ms)16932026-09-10 17:37:20.564 UTC [99882] ERROR: relation "goose_db_version" does not exist at character 3616942026-09-10 17:37:20.564 UTC [99882] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1695=== NAME TestOrphanedObjectsGCStressTest1696 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16972026/09/10 17:37:20 OK 20260628120000_add_object_size_and_stats.sql (16.34ms)16982026/09/10 17:37:20 OK 20260905000000_add_claims.sql (3.8ms)16992026/09/10 17:37:20 goose: successfully migrated database to version: 2026090500000017002026/09/10 17:37:20 OK 1_commit_pending_closure.sql (2.08ms)17012026/09/10 17:37:20 OK 2_object_stats_trigger.sql (572.58µs)17022026/09/10 17:37:20 goose: up to current file version: 217032026/09/10 17:37:20 OK 20241026095416_initial_model.sql (31.54ms)1704 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17052026/09/10 17:37:20 OK 20251210153512_drop_unused_gin_index.sql (7.7ms)17062026/09/10 17:37:20 OK 20251218171726_add_pins.sql (24.93ms)17072026/09/10 17:37:20 OK 20260628120000_add_object_size_and_stats.sql (18.14ms)17082026/09/10 17:37:20 OK 20260905000000_add_claims.sql (36.9ms)17092026/09/10 17:37:20 goose: successfully migrated database to version: 2026090500000017102026/09/10 17:37:20 OK 1_commit_pending_closure.sql (2.24ms)17112026/09/10 17:37:20 OK 2_object_stats_trigger.sql (536.21µs)17122026/09/10 17:37:20 goose: up to current file version: 21713--- PASS: TestService_ReadAuthMiddleware (1.58s)1714=== CONT TestClientMultipleUploads17152026-09-10 17:37:20.977 UTC [99886] ERROR: relation "goose_db_version" does not exist at character 3617162026-09-10 17:37:20.977 UTC [99886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17172026-09-10 17:37:20.979 UTC [99887] ERROR: relation "goose_db_version" does not exist at character 3617182026-09-10 17:37:20.979 UTC [99887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17192026-09-10 17:37:20.982 UTC [99888] ERROR: relation "goose_db_version" does not exist at character 3617202026-09-10 17:37:20.982 UTC [99888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17212026-09-10 17:37:20.993 UTC [99889] ERROR: relation "goose_db_version" does not exist at character 3617222026-09-10 17:37:20.993 UTC [99889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17232026/09/10 17:37:21 OK 20241026095416_initial_model.sql (6.14ms)17242026/09/10 17:37:21 OK 20241026095416_initial_model.sql (7.74ms)17252026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (543.25µs)17262026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (513.79µs)17272026/09/10 17:37:21 OK 20251218171726_add_pins.sql (2.08ms)17282026/09/10 17:37:21 OK 20241026095416_initial_model.sql (8.36ms)17292026/09/10 17:37:21 OK 20251218171726_add_pins.sql (3.07ms)17302026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (588.46µs)17312026/09/10 17:37:21 OK 20241026095416_initial_model.sql (11.53ms)17322026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (398.88µs)17332026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (1.75ms)17342026/09/10 17:37:21 OK 20251218171726_add_pins.sql (1.67ms)17352026/09/10 17:37:21 OK 20251218171726_add_pins.sql (1.03ms)17362026/09/10 17:37:21 OK 20260905000000_add_claims.sql (1.07ms)17372026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000017382026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)17392026/09/10 17:37:21 OK 1_commit_pending_closure.sql (1.5ms)17402026/09/10 17:37:21 OK 2_object_stats_trigger.sql (266.54µs)17412026/09/10 17:37:21 goose: up to current file version: 217422026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)17432026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)17442026/09/10 17:37:21 OK 20260905000000_add_claims.sql (1.97ms)17452026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000017462026/09/10 17:37:21 OK 1_commit_pending_closure.sql (1.33ms)17472026/09/10 17:37:21 OK 2_object_stats_trigger.sql (211.67µs)17482026/09/10 17:37:21 goose: up to current file version: 217492026/09/10 17:37:21 OK 20260905000000_add_claims.sql (19.59ms)17502026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000017512026/09/10 17:37:21 OK 20260905000000_add_claims.sql (20.89ms)17522026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000017532026/09/10 17:37:21 OK 1_commit_pending_closure.sql (2.27ms)17542026/09/10 17:37:21 OK 1_commit_pending_closure.sql (929.17µs)17552026/09/10 17:37:21 OK 2_object_stats_trigger.sql (209.04µs)17562026/09/10 17:37:21 goose: up to current file version: 217572026/09/10 17:37:21 OK 2_object_stats_trigger.sql (190.25µs)17582026/09/10 17:37:21 goose: up to current file version: 21759=== NAME TestClientIntegration1760 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-99207-761247270/TestClientIntegration3780575920/002/store/l8pqq4918rwv0z67q8jm2gw1f6gb5m74-test-file.txt17612026-09-10 17:37:21.162 UTC [99895] ERROR: relation "goose_db_version" does not exist at character 3617622026-09-10 17:37:21.162 UTC [99895] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17632026/09/10 17:37:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17642026-09-10 17:37:21.207 UTC [99897] ERROR: relation "goose_db_version" does not exist at character 3617652026-09-10 17:37:21.207 UTC [99897] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17662026/09/10 17:37:21 INFO Received uploads request method=POST path=/api/pending_closures17672026/09/10 17:37:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17682026/09/10 17:37:21 INFO Uploading l8pqq4918rwv0z67q8jm2gw1f6gb5m74-test-file.txt (152B)17692026/09/10 17:37:21 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1770--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.18s)1771=== CONT TestMetricsInventory17722026/09/10 17:37:21 WARN Failed to register uploaded object key=l8pqq4918rwv0z67q8jm2gw1f6gb5m74.ls error="server returned 404: 404 page not found\n"17732026/09/10 17:37:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17742026/09/10 17:37:21 INFO Signed narinfos id=1 count=117752026/09/10 17:37:21 INFO Uploading 1 narinfos17762026/09/10 17:37:21 WARN Failed to register uploaded object key=l8pqq4918rwv0z67q8jm2gw1f6gb5m74.narinfo error="server returned 404: 404 page not found\n"17772026/09/10 17:37:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17782026/09/10 17:37:21 OK 20241026095416_initial_model.sql (67.73ms)17792026/09/10 17:37:21 INFO Completed upload id=117802026/09/10 17:37:21 INFO Upload complete. (143ms)17812026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (6.78ms)1782=== NAME TestClientIntegration1783 client_integration_test.go:293: Retrieved narinfo from S3:1784 StorePath: /nix/var/nix/builds/nix-99207-761247270/TestClientIntegration3780575920/002/store/l8pqq4918rwv0z67q8jm2gw1f6gb5m74-test-file.txt1785 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1786 Compression: zstd1787 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11788 NarSize: 1521789 References: 1790 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117912026/09/10 17:37:21 OK 20251218171726_add_pins.sql (1.19ms)1792 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1793 client_integration_test.go:294: Decompressed .ls content (64 bytes):1794 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1795 client_integration_test.go:297: Testing garbage collection...17962026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (16.72ms)17972026/09/10 17:37:21 OK 20241026095416_initial_model.sql (67.93ms)17982026/09/10 17:37:21 OK 20260905000000_add_claims.sql (12.5ms)17992026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000018002026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)18012026/09/10 17:37:21 OK 1_commit_pending_closure.sql (1.43ms)18022026/09/10 17:37:21 OK 2_object_stats_trigger.sql (383.29µs)18032026/09/10 17:37:21 goose: up to current file version: 218042026/09/10 17:37:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures18052026/09/10 17:37:21 INFO Garbage collection started18062026/09/10 17:37:21 INFO Aborted multipart uploads count=018072026/09/10 17:37:21 WARN Force mode enabled - objects will be deleted immediately without grace period18082026/09/10 17:37:21 OK 20251218171726_add_pins.sql (16.36ms)18092026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (13.69ms)18102026/09/10 17:37:21 OK 20260905000000_add_claims.sql (31.17ms)18112026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000018122026/09/10 17:37:21 OK 1_commit_pending_closure.sql (1.57ms)18132026/09/10 17:37:21 OK 2_object_stats_trigger.sql (219µs)18142026/09/10 17:37:21 goose: up to current file version: 21815--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.39s)1816=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18172026/09/10 17:37:21 INFO Received uploads request method=POST path=/18182026-09-10 17:37:21.390 UTC [99904] ERROR: relation "goose_db_version" does not exist at character 3618192026-09-10 17:37:21.390 UTC [99904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18202026/09/10 17:37:21 OK 20241026095416_initial_model.sql (35.97ms)18212026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (576.63µs)18222026/09/10 17:37:21 OK 20251218171726_add_pins.sql (6.14ms)18232026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (14.42ms)18242026/09/10 17:37:21 OK 20260905000000_add_claims.sql (21.93ms)18252026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000018262026/09/10 17:37:21 OK 1_commit_pending_closure.sql (6.22ms)18272026/09/10 17:37:21 OK 2_object_stats_trigger.sql (217.75µs)18282026/09/10 17:37:21 goose: up to current file version: 218292026/09/10 17:37:21 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=018302026/09/10 17:37:21 INFO Vacuumed table table=pending_closures18312026/09/10 17:37:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18322026/09/10 17:37:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1833--- PASS: TestService_NativeMTLS (1.44s)1834=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18352026/09/10 17:37:21 INFO Received uploads request method=POST path=/1836=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18372026/09/10 17:37:21 INFO Received request for more parts method=POST path=/18382026/09/10 17:37:21 INFO Vacuumed table table=pending_objects18392026/09/10 17:37:21 INFO Vacuumed table table=multipart_uploads18402026/09/10 17:37:21 INFO Vacuumed table table=closures1841=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18422026/09/10 17:37:21 INFO Received complete multipart upload request method=POST path=/18432026/09/10 17:37:21 INFO Vacuumed table table=objects1844=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18452026/09/10 17:37:21 INFO Received complete multipart upload request method=POST path=/1846=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18472026/09/10 17:37:21 INFO Received request for more parts method=POST path=/1848=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18492026/09/10 17:37:21 INFO Received uploads request method=POST path=/1850--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1851 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1852 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1853 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1854 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1855=== CONT TestIsValidUploadKey/narinfo1856=== CONT TestIsValidUploadKey/realisation_plus_in_output1857=== CONT TestIsValidUploadKey/unknown_type1858=== CONT TestIsValidUploadKey/empty_key1859=== CONT TestIsValidUploadKey/absolute1860=== CONT TestIsValidUploadKey/traversal_nar1861=== CONT TestIsValidUploadKey/traversal1862=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1863=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1864=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1865=== CONT TestIsValidUploadKey/index.html1866=== CONT TestIsValidUploadKey/nix-cache-info1867=== CONT TestIsValidUploadKey/build_log_equals1868=== CONT TestIsValidUploadKey/realisation1869=== CONT TestIsValidUploadKey/build_log_home-manager_file1870=== CONT TestIsValidUploadKey/build_log_question_mark1871=== CONT TestIsValidUploadKey/build_log_plus_in_name1872=== CONT TestIsValidUploadKey/nar_plain1873=== CONT TestIsValidUploadKey/build_log1874=== CONT TestIsValidUploadKey/listing1875=== CONT TestIsValidUploadKey/nar_xz1876=== CONT TestIsValidUploadKey/nar_zst1877--- PASS: TestIsValidUploadKey (0.00s)1878 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1879 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1880 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1881 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1882 --- PASS: TestIsValidUploadKey/absolute (0.00s)1883 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1884 --- PASS: TestIsValidUploadKey/traversal (0.00s)1885 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1886 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1887 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1888 --- PASS: TestIsValidUploadKey/index.html (0.00s)1889 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1890 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1891 --- PASS: TestIsValidUploadKey/realisation (0.00s)1892 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1893 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1894 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1895 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1896 --- PASS: TestIsValidUploadKey/build_log (0.00s)1897 --- PASS: TestIsValidUploadKey/listing (0.00s)1898 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1899 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1900=== CONT TestProxyWriteTimeout/narinfo1901=== CONT TestProxyWriteTimeout/10_GiB_nar1902=== CONT TestProxyWriteTimeout/unknown_size1903=== CONT TestProxyWriteTimeout/1_GiB_nar1904--- PASS: TestProxyWriteTimeout (0.00s)1905 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1906 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1907 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1908 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1909=== CONT TestIsValidCachePath/narinfo1910=== CONT TestIsValidCachePath/index.html1911=== CONT TestIsValidCachePath/short_hash1912=== CONT TestIsValidCachePath/wrong_extension1913=== CONT TestIsValidCachePath/leading_slash1914=== CONT TestIsValidCachePath/empty1915=== CONT TestIsValidCachePath/random_path1916=== CONT TestIsValidCachePath/invalid_char_u1917=== CONT TestIsValidCachePath/traversal_parent1918=== CONT TestIsValidCachePath/invalid_char_e1919=== CONT TestIsValidCachePath/nar_uncompressed1920=== CONT TestIsValidCachePath/nix-cache-info1921=== CONT TestIsValidCachePath/traversal_in_middle1922=== CONT TestIsValidCachePath/realisation1923=== CONT TestIsValidCachePath/nar_xz1924=== CONT TestIsValidCachePath/log1925=== CONT TestIsValidCachePath/nar_bz21926=== CONT TestIsValidCachePath/ls1927=== CONT TestIsValidCachePath/nar_zst1928=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1929--- PASS: TestIsValidCachePath (0.00s)1930 --- PASS: TestIsValidCachePath/narinfo (0.00s)1931 --- PASS: TestIsValidCachePath/index.html (0.00s)1932 --- PASS: TestIsValidCachePath/short_hash (0.00s)1933 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1934 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1935 --- PASS: TestIsValidCachePath/empty (0.00s)1936 --- PASS: TestIsValidCachePath/random_path (0.00s)1937 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1938 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1939 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1940 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1941 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1942 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1943 --- PASS: TestIsValidCachePath/realisation (0.00s)1944 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1945 --- PASS: TestIsValidCachePath/log (0.00s)1946 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1947 --- PASS: TestIsValidCachePath/ls (0.00s)1948 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1949 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1950=== CONT TestParseSingleRange/none1951=== CONT TestParseSingleRange/open-ended1952=== CONT TestParseSingleRange/start_far_past_EOF1953=== CONT TestParseSingleRange/start_past_EOF1954=== CONT TestParseSingleRange/single_byte1955=== CONT TestParseSingleRange/suffix_exceeds_size1956=== CONT TestParseSingleRange/suffix1957=== CONT TestParseSingleRange/end_clamped_to_size1958=== CONT TestParseSingleRange/malformed_both_empty1959=== CONT TestParseSingleRange/closed1960=== CONT TestParseSingleRange/malformed_end_before_start1961=== CONT TestParseSingleRange/multi-range_ignored1962=== CONT TestParseSingleRange/malformed_no_dash1963=== CONT TestParseSingleRange/unknown_unit1964--- PASS: TestParseSingleRange (0.00s)1965 --- PASS: TestParseSingleRange/none (0.00s)1966 --- PASS: TestParseSingleRange/open-ended (0.00s)1967 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1968 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1969 --- PASS: TestParseSingleRange/single_byte (0.00s)1970 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1971 --- PASS: TestParseSingleRange/suffix (0.00s)1972 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1973 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1974 --- PASS: TestParseSingleRange/closed (0.00s)1975 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1976 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1977 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1978 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1979=== CONT TestCacheConfigHandler/full_config,_no_issuer1980=== CONT TestServerTLSConfig/no_client_CA1981=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1982=== CONT TestCacheConfigHandler/no_signing_keys1983=== CONT TestCacheConfigHandler/no_cache_url_configured1984=== CONT TestServerTLSConfig/not_a_PEM_file1985--- PASS: TestCacheConfigHandler (0.00s)1986 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1987 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1988 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1989 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1990=== CONT TestServerTLSConfig/missing_CA_file1991--- PASS: TestServerTLSConfig (0.00s)1992 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1993 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1994 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1995=== CONT TestService_RequireScope_OIDC/builder_may_write19962026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[write]1997=== CONT TestService_RequireScope_OIDC/static_token_may_admin1998=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1999=== CONT TestService_RequireScope_OIDC/writer_implies_read20002026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[write]2001=== CONT TestService_RequireScope_OIDC/reader_may_read20022026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[read]2003=== CONT TestService_RequireScope_OIDC/static_token_may_write2004=== CONT TestService_RequireScope_OIDC/ops_may_not_write20052026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[admin]2006=== CONT TestService_RequireScope_OIDC/reader_may_not_write20072026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[read]2008=== CONT TestService_RequireScope_OIDC/ops_may_admin20092026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[admin]2010=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20112026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[write]2012=== CONT TestResolveDBConnectionString/flag_wins2013=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2014=== CONT TestResolveDBConnectionString/nothing_configured2015=== CONT TestResolveDBConnectionString/missing_file_is_an_error2016=== CONT TestResolveDBConnectionString/file_when_flag_empty2017=== CONT TestClientErrorHandling/InvalidStorePath2018--- PASS: TestResolveDBConnectionString (0.00s)2019 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2020 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2021 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2022 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2023 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2024--- PASS: TestService_RequireScope_OIDC (2.43s)2025 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2026 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2027 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20352026-09-10 17:37:21.593 UTC [99907] ERROR: relation "goose_db_version" does not exist at character 3620362026-09-10 17:37:21.593 UTC [99907] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20372026/09/10 17:37:21 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20382026/09/10 17:37:21 WARN mTLS auth: bound subjects configured but subject DN unavailable20392026/09/10 17:37:21 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2040--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.69s)2041=== CONT TestClientErrorHandling/ServerNotAvailable20422026/09/10 17:37:21 OK 20241026095416_initial_model.sql (58.46ms)20432026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (10.92ms)2044--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2045 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2046 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2047 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)2048=== CONT TestClientErrorHandling/InvalidAuthToken20492026/09/10 17:37:21 OK 20251218171726_add_pins.sql (12.43ms)20502026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (12.05ms)20512026/09/10 17:37:21 OK 20260905000000_add_claims.sql (28.88ms)20522026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000020532026/09/10 17:37:21 OK 1_commit_pending_closure.sql (2.16ms)20542026/09/10 17:37:21 OK 2_object_stats_trigger.sql (237.38µs)20552026/09/10 17:37:21 goose: up to current file version: 22056=== NAME TestOrphanedObjectsGCStressTest2057 orphaned_objects_gc_test.go:509: Stress test completed successfully:2058 orphaned_objects_gc_test.go:510: - Active objects preserved: 202059 orphaned_objects_gc_test.go:511: - Objects deleted: 2102060 orphaned_objects_gc_test.go:512: - Total GC'd: 2102061--- PASS: TestOrphanedObjectsGCStressTest (7.76s)2062=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20632026/09/10 17:37:21 INFO OIDC auth successful provider=test scopes=[write]2064=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20652026/09/10 17:37:21 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]2066=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2067=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20682026/09/10 17:37:21 WARN Authentication failed token_preview=eyJhbGciOi...2ba0tzMgLA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2069--- PASS: TestService_AuthMiddleware_OIDC (2.13s)2070 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2071 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2072 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2073 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20742026/09/10 17:37:21 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-config20752026-09-10 17:37:21.862 UTC [99918] ERROR: relation "goose_db_version" does not exist at character 3620762026-09-10 17:37:21.862 UTC [99918] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20772026/09/10 17:37:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.750698ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20782026/09/10 17:37:21 OK 20241026095416_initial_model.sql (56.36ms)20792026/09/10 17:37:21 OK 20251210153512_drop_unused_gin_index.sql (691µs)2080=== NAME TestPinProtectsFromGC2081 client_integration_test.go:648: Pinned store path: /nix/var/nix/builds/nix-99207-761247270/TestPinProtectsFromGC1638112049/001/store/lgdyn9mrq8hvxf640nkymfx1wc55wska-pinned-file.txt2082 client_integration_test.go:649: Unpinned store path: /nix/var/nix/builds/nix-99207-761247270/TestPinProtectsFromGC1638112049/001/store/arlncl22wncflrp7y95r2py9gjilgs53-unpinned-file.txt20832026/09/10 17:37:21 OK 20251218171726_add_pins.sql (2.25ms)2084--- PASS: TestReadProxyRangeRequest (1.62s)20852026/09/10 17:37:21 OK 20260628120000_add_object_size_and_stats.sql (14.63ms)20862026/09/10 17:37:21 OK 20260905000000_add_claims.sql (4.9ms)20872026/09/10 17:37:21 goose: successfully migrated database to version: 2026090500000020882026/09/10 17:37:21 OK 1_commit_pending_closure.sql (1.05ms)20892026/09/10 17:37:21 OK 2_object_stats_trigger.sql (198.46µs)20902026/09/10 17:37:21 goose: up to current file version: 220912026/09/10 17:37:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20922026/09/10 17:37:22 INFO Received uploads request method=POST path=/api/pending_closures20932026/09/10 17:37:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20942026/09/10 17:37:22 INFO Uploading lgdyn9mrq8hvxf640nkymfx1wc55wska-pinned-file.txt (128B)20952026/09/10 17:37:22 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20962026/09/10 17:37:22 WARN Failed to register uploaded object key=lgdyn9mrq8hvxf640nkymfx1wc55wska.ls error="server returned 404: 404 page not found\n"20972026/09/10 17:37:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20982026/09/10 17:37:22 INFO Signed narinfos id=1 count=120992026/09/10 17:37:22 INFO Uploading 1 narinfos21002026/09/10 17:37:22 WARN Failed to register uploaded object key=lgdyn9mrq8hvxf640nkymfx1wc55wska.narinfo error="server returned 404: 404 page not found\n"21012026/09/10 17:37:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21022026/09/10 17:37:22 INFO Completed upload id=121032026/09/10 17:37:22 INFO Upload complete. (108ms)21042026-09-10 17:37:22.107 UTC [99934] ERROR: relation "goose_db_version" does not exist at character 3621052026-09-10 17:37:22.107 UTC [99934] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21062026/09/10 17:37:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.159426ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21072026/09/10 17:37:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21082026/09/10 17:37:22 OK 20241026095416_initial_model.sql (30.7ms)21092026/09/10 17:37:22 OK 20251210153512_drop_unused_gin_index.sql (5.74ms)21102026/09/10 17:37:22 OK 20251218171726_add_pins.sql (1.2ms)21112026/09/10 17:37:22 OK 20260628120000_add_object_size_and_stats.sql (7.63ms)21122026/09/10 17:37:22 INFO Received uploads request method=POST path=/api/pending_closures21132026/09/10 17:37:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21142026/09/10 17:37:22 INFO Uploading arlncl22wncflrp7y95r2py9gjilgs53-unpinned-file.txt (128B)21152026/09/10 17:37:22 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"21162026/09/10 17:37:22 WARN Failed to register uploaded object key=arlncl22wncflrp7y95r2py9gjilgs53.ls error="server returned 404: 404 page not found\n"21172026/09/10 17:37:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21182026/09/10 17:37:22 INFO Signed narinfos id=2 count=121192026/09/10 17:37:22 INFO Uploading 1 narinfos21202026/09/10 17:37:22 OK 20260905000000_add_claims.sql (19.16ms)21212026/09/10 17:37:22 goose: successfully migrated database to version: 2026090500000021222026/09/10 17:37:22 WARN Failed to register uploaded object key=arlncl22wncflrp7y95r2py9gjilgs53.narinfo error="server returned 404: 404 page not found\n"21232026/09/10 17:37:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21242026/09/10 17:37:22 INFO Completed upload id=221252026/09/10 17:37:22 INFO Upload complete. (85ms)21262026/09/10 17:37:22 OK 1_commit_pending_closure.sql (1.38ms)21272026/09/10 17:37:22 OK 2_object_stats_trigger.sql (730.42µs)21282026/09/10 17:37:22 goose: up to current file version: 221292026-09-10 17:37:22.218 UTC [99946] ERROR: relation "goose_db_version" does not exist at character 3621302026-09-10 17:37:22.218 UTC [99946] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21312026/09/10 17:37:22 INFO Received create pin request method=POST path=/api/pins/myapp21322026/09/10 17:37:22 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-99207-761247270/TestPinProtectsFromGC1638112049/001/store/lgdyn9mrq8hvxf640nkymfx1wc55wska-pinned-file.txt narinfo_key=lgdyn9mrq8hvxf640nkymfx1wc55wska.narinfo21332026/09/10 17:37:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures21342026/09/10 17:37:22 INFO Garbage collection started21352026/09/10 17:37:22 INFO Aborted multipart uploads count=021362026/09/10 17:37:22 WARN Force mode enabled - objects will be deleted immediately without grace period21372026/09/10 17:37:22 OK 20241026095416_initial_model.sql (17.34ms)21382026/09/10 17:37:22 OK 20251210153512_drop_unused_gin_index.sql (5.14ms)21392026/09/10 17:37:22 OK 20251218171726_add_pins.sql (5.54ms)21402026/09/10 17:37:22 OK 20260628120000_add_object_size_and_stats.sql (15.15ms)21412026/09/10 17:37:22 OK 20260905000000_add_claims.sql (8.35ms)21422026/09/10 17:37:22 goose: successfully migrated database to version: 202609050000002143=== NAME TestClientMultipleUploads2144 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-99207-761247270/TestClientMultipleUploads2162081474/001/store/qjw1199dfqglrh5zb3nxa39yq5cdxpd8-test-file-0.txt21452026/09/10 17:37:22 OK 1_commit_pending_closure.sql (7.78ms)21462026/09/10 17:37:22 OK 2_object_stats_trigger.sql (298.38µs)21472026/09/10 17:37:22 goose: up to current file version: 22148=== NAME TestClientWithDependencies2149 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-99207-761247270/TestClientWithDependencies4002511200/001/store/slchd17pk0yki1wic5jfzi1974860hw4-test-script2150--- PASS: TestMetricsInventory (1.08s)2151=== NAME TestClientWithDependencies2152 client_integration_test.go:596: Found 1 dependencies (including self)2153=== NAME TestClientMultipleUploads2154 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-99207-761247270/TestClientMultipleUploads2162081474/001/store/bs2q6llvpv3i7cnlxx3yr2kk5sfwkk3m-test-file-1.txt2155 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-99207-761247270/TestClientMultipleUploads2162081474/001/store/v8sdgclc30ccyzz9l4i35l584747vr01-test-file-2.txt21562026/09/10 17:37:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21572026/09/10 17:37:22 INFO Received uploads request method=POST path=/api/pending_closures21582026/09/10 17:37:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21592026/09/10 17:37:22 INFO Uploading slchd17pk0yki1wic5jfzi1974860hw4-test-script (136B)21602026/09/10 17:37:22 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"21612026/09/10 17:37:22 WARN Failed to register uploaded object key=log/bdvnddbfl2c45p2r9y4y7jpv5lhyiz6g-test-script.drv error="server returned 404: 404 page not found\n"21622026/09/10 17:37:22 WARN Failed to register uploaded object key=slchd17pk0yki1wic5jfzi1974860hw4.ls error="server returned 404: 404 page not found\n"21632026/09/10 17:37:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21642026/09/10 17:37:22 INFO Signed narinfos id=1 count=121652026/09/10 17:37:22 INFO Uploading 1 narinfos21662026/09/10 17:37:22 WARN Failed to register uploaded object key=slchd17pk0yki1wic5jfzi1974860hw4.narinfo error="server returned 404: 404 page not found\n"21672026/09/10 17:37:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21682026/09/10 17:37:22 INFO Completed upload id=121692026/09/10 17:37:22 INFO Upload complete. (66ms)2170=== NAME TestClientWithDependencies2171 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-99207-761247270/TestClientWithDependencies4002511200/001/store) requires matching store prefix21722026/09/10 17:37:22 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=021732026/09/10 17:37:22 INFO Vacuumed table table=pending_closures21742026/09/10 17:37:22 INFO Vacuumed table table=pending_objects21752026/09/10 17:37:22 INFO Vacuumed table table=multipart_uploads2176--- PASS: TestClientWithDependencies (1.93s)21772026/09/10 17:37:22 INFO Vacuumed table table=closures21782026/09/10 17:37:22 INFO Vacuumed table table=objects21792026/09/10 17:37:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21802026/09/10 17:37:22 INFO Received uploads request method=POST path=/api/pending_closures21812026/09/10 17:37:22 INFO Received uploads request method=POST path=/api/pending_closures21822026/09/10 17:37:22 INFO Received uploads request method=POST path=/api/pending_closures21832026/09/10 17:37:22 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)21842026/09/10 17:37:22 INFO Uploading v8sdgclc30ccyzz9l4i35l584747vr01-test-file-2.txt (160B)21852026/09/10 17:37:22 INFO Uploading qjw1199dfqglrh5zb3nxa39yq5cdxpd8-test-file-0.txt (160B)21862026/09/10 17:37:22 INFO Uploading bs2q6llvpv3i7cnlxx3yr2kk5sfwkk3m-test-file-1.txt (160B)21872026/09/10 17:37:22 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"21882026/09/10 17:37:22 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"21892026/09/10 17:37:22 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"21902026/09/10 17:37:22 WARN Failed to register uploaded object key=bs2q6llvpv3i7cnlxx3yr2kk5sfwkk3m.ls error="server returned 404: 404 page not found\n"21912026/09/10 17:37:22 WARN Failed to register uploaded object key=v8sdgclc30ccyzz9l4i35l584747vr01.ls error="server returned 404: 404 page not found\n"21922026/09/10 17:37:22 WARN Failed to register uploaded object key=qjw1199dfqglrh5zb3nxa39yq5cdxpd8.ls error="server returned 404: 404 page not found\n"21932026/09/10 17:37:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21942026/09/10 17:37:22 INFO Signed narinfos id=2 count=121952026/09/10 17:37:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21962026/09/10 17:37:22 INFO Signed narinfos id=3 count=121972026/09/10 17:37:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21982026/09/10 17:37:22 INFO Signed narinfos id=1 count=121992026/09/10 17:37:22 INFO Uploading 3 narinfos22002026/09/10 17:37:22 WARN Failed to register uploaded object key=qjw1199dfqglrh5zb3nxa39yq5cdxpd8.narinfo error="server returned 404: 404 page not found\n"22012026/09/10 17:37:22 WARN Failed to register uploaded object key=bs2q6llvpv3i7cnlxx3yr2kk5sfwkk3m.narinfo error="server returned 404: 404 page not found\n"22022026/09/10 17:37:22 WARN Failed to register uploaded object key=v8sdgclc30ccyzz9l4i35l584747vr01.narinfo error="server returned 404: 404 page not found\n"22032026/09/10 17:37:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22042026/09/10 17:37:22 INFO Completed upload id=122052026/09/10 17:37:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22062026/09/10 17:37:22 INFO Completed upload id=222072026/09/10 17:37:22 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete22082026/09/10 17:37:22 INFO Completed upload id=322092026/09/10 17:37:22 INFO Upload complete. (122ms)2210=== NAME TestClientMultipleUploads2211 client_integration_test.go:350: Uploaded 3 paths in 157.314375ms2212--- PASS: TestClientMultipleUploads (1.77s)22132026/09/10 17:37:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.620087ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22142026/09/10 17:37:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22152026/09/10 17:37:22 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22162026/09/10 17:37:23 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02217=== NAME TestClientIntegration2218 client_integration_test.go:304: Objects in database after GC:2219 client_integration_test.go:304: Successfully deleted all objects with GC --force22202026/09/10 17:37:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.52986535s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2221--- PASS: TestClientIntegration (3.82s)22222026/09/10 17:37:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02223=== NAME TestPinProtectsFromGC2224 client_integration_test.go:711: Pin successfully protected closure from garbage collection2225--- PASS: TestPinProtectsFromGC (3.93s)22262026/09/10 17:37:24 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"22272026/09/10 17:37:24 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_closures22282026/09/10 17:37:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.239747ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22292026/09/10 17:37:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.478583ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22302026/09/10 17:37:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=846.221788ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22312026/09/10 17:37:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74822097s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2232--- PASS: TestClientErrorHandling (0.00s)2233 --- PASS: TestClientErrorHandling/InvalidStorePath (0.87s)2234 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.98s)2235 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.64s)2236PASS22372026-09-10 17:37:31.504 UTC [99426] LOG: received smart shutdown request22382026-09-10 17:37:31.507 UTC [99426] LOG: background worker "logical replication launcher" (PID 99436) exited with exit code 122392026-09-10 17:37:31.931 UTC [99431] LOG: shutting down22402026-09-10 17:37:31.936 UTC [99431] LOG: checkpoint starting: shutdown immediate22412026/09/10 17:37:38 ERROR failed to kill rustfs error="no such process"22422026-09-10 17:37:39.360 UTC [99431] LOG: checkpoint complete: wrote 12868 buffers (78.5%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=4.984 s, sync=2.291 s, total=7.429 s; sync files=21000, longest=0.014 s, average=0.001 s; distance=287764 kB, estimate=287764 kB; lsn=0/13092318, redo lsn=0/1309231822432026-09-10 17:37:39.499 UTC [99426] LOG: database system is shut down22442026/09/10 17:37:41 ERROR failed to kill rustfs error="no such process"2245Running OIDC tests...2246=== RUN TestGlobMatch2247=== PAUSE TestGlobMatch2248=== RUN TestAudienceForIssuer2249=== PAUSE TestAudienceForIssuer2250=== RUN TestValidateToken_ValidToken2251=== PAUSE TestValidateToken_ValidToken2252=== RUN TestValidateToken_WrongAudience2253=== PAUSE TestValidateToken_WrongAudience2254=== RUN TestValidateToken_Expired2255=== PAUSE TestValidateToken_Expired2256=== RUN TestValidateToken_BoundClaimsMismatch2257=== PAUSE TestValidateToken_BoundClaimsMismatch2258=== RUN TestValidateToken_BoundSubjectMismatch2259=== PAUSE TestValidateToken_BoundSubjectMismatch2260=== RUN TestValidateToken_MultipleProviders2261=== PAUSE TestValidateToken_MultipleProviders2262=== RUN TestValidateToken_NoMatchingProvider2263=== PAUSE TestValidateToken_NoMatchingProvider2264=== RUN TestValidateToken_KubernetesServiceAccount2265=== PAUSE TestValidateToken_KubernetesServiceAccount2266=== RUN TestNewValidator_KubernetesRequiresCA2267=== PAUSE TestNewValidator_KubernetesRequiresCA2268=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2269=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2270=== RUN TestScopes_LegacyProviderDefaultsToWrite2271=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2272=== RUN TestScopes_Rules2273=== PAUSE TestScopes_Rules2274=== RUN TestScopes_ConfigValidation2275=== PAUSE TestScopes_ConfigValidation2276=== CONT TestGlobMatch2277=== CONT TestValidateToken_NoMatchingProvider2278=== RUN TestGlobMatch/foo_foo2279=== CONT TestValidateToken_MultipleProviders2280=== CONT TestScopes_LegacyProviderDefaultsToWrite2281=== CONT TestScopes_ConfigValidation2282=== CONT TestNewValidator_KubernetesRequiresCA2283=== CONT TestValidateToken_BoundSubjectMismatch2284=== PAUSE TestGlobMatch/foo_foo2285=== RUN TestGlobMatch/foo_bar2286=== CONT TestScopes_Rules2287=== CONT TestValidateToken_WrongAudience2288=== CONT TestValidateToken_Expired2289=== PAUSE TestGlobMatch/foo_bar2290=== RUN TestGlobMatch/*_2291=== PAUSE TestGlobMatch/*_2292=== RUN TestGlobMatch/*_anything2293=== PAUSE TestGlobMatch/*_anything2294=== RUN TestGlobMatch/foo*_foo2295=== PAUSE TestGlobMatch/foo*_foo2296=== RUN TestGlobMatch/foo*_foobar2297=== PAUSE TestGlobMatch/foo*_foobar2298=== RUN TestGlobMatch/foo*_bar2299=== PAUSE TestGlobMatch/foo*_bar2300=== RUN TestGlobMatch/*bar_bar2301=== PAUSE TestGlobMatch/*bar_bar2302=== RUN TestGlobMatch/*bar_foobar2303=== PAUSE TestGlobMatch/*bar_foobar2304=== RUN TestGlobMatch/*bar_foo2305=== PAUSE TestGlobMatch/*bar_foo2306=== RUN TestGlobMatch/foo*bar_foobar2307=== PAUSE TestGlobMatch/foo*bar_foobar2308=== RUN TestGlobMatch/foo*bar_foo123bar2309=== PAUSE TestGlobMatch/foo*bar_foo123bar2310=== RUN TestGlobMatch/foo*bar_foobarbaz2311=== PAUSE TestGlobMatch/foo*bar_foobarbaz2312=== RUN TestGlobMatch/*/*_foo/bar2313=== PAUSE TestGlobMatch/*/*_foo/bar2314=== RUN TestGlobMatch/*/*_foo2315=== PAUSE TestGlobMatch/*/*_foo2316=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2317=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2318=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02319=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02320=== RUN TestGlobMatch/refs/*/main_refs/heads/main2321=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2322=== RUN TestGlobMatch/fo?_foo2323=== PAUSE TestGlobMatch/fo?_foo2324=== RUN TestGlobMatch/fo?_fo2325=== PAUSE TestGlobMatch/fo?_fo2326=== RUN TestGlobMatch/fo?_fooo2327=== PAUSE TestGlobMatch/fo?_fooo2328=== RUN TestGlobMatch/?oo_foo2329=== PAUSE TestGlobMatch/?oo_foo2330=== RUN TestGlobMatch/?oo_boo2331=== PAUSE TestGlobMatch/?oo_boo2332=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2333=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2334=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2335=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2336=== CONT TestValidateToken_BoundClaimsMismatch2337--- PASS: TestScopes_ConfigValidation (0.00s)2338=== CONT TestValidateToken_ValidToken23392026/09/10 17:37:43 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50497/oidc23402026/09/10 17:37:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50499/oidc23412026/09/10 17:37:43 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50496/oidc23422026/09/10 17:37:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50501/oidc23432026/09/10 17:37:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50498/oidc23442026/09/10 17:37:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50500/oidc23452026/09/10 17:37:43 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:50503/oidc23462026/09/10 17:37:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50505/oidc23472026/09/10 17:37:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50513/oidc2348--- PASS: TestValidateToken_WrongAudience (0.01s)2349=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2350--- PASS: TestValidateToken_Expired (0.01s)2351=== CONT TestAudienceForIssuer2352--- PASS: TestAudienceForIssuer (0.00s)2353--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2354=== CONT TestValidateToken_KubernetesServiceAccount2355=== CONT TestGlobMatch/foo_foo2356=== CONT TestGlobMatch/*/*_foo/bar2357=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2358=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2359=== CONT TestGlobMatch/?oo_boo2360=== CONT TestGlobMatch/?oo_foo2361=== CONT TestGlobMatch/fo?_fooo2362=== CONT TestGlobMatch/fo?_fo2363=== CONT TestGlobMatch/fo?_foo2364=== CONT TestGlobMatch/refs/*/main_refs/heads/main2365=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02366=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2367=== CONT TestGlobMatch/*/*_foo2368=== CONT TestGlobMatch/*bar_bar2369=== CONT TestGlobMatch/foo*bar_foobarbaz2370=== CONT TestGlobMatch/foo*bar_foo123bar2371=== CONT TestGlobMatch/foo*bar_foobar2372=== CONT TestGlobMatch/*bar_foo2373=== CONT TestGlobMatch/*bar_foobar2374=== CONT TestGlobMatch/foo*_foo2375=== CONT TestGlobMatch/foo*_bar2376=== CONT TestGlobMatch/foo*_foobar2377=== CONT TestGlobMatch/*_2378=== CONT TestGlobMatch/*_anything2379=== CONT TestGlobMatch/foo_bar2380--- PASS: TestGlobMatch (0.00s)2381 --- PASS: TestGlobMatch/foo_foo (0.00s)2382 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2383 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2384 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2385 --- PASS: TestGlobMatch/?oo_boo (0.00s)2386 --- PASS: TestGlobMatch/?oo_foo (0.00s)2387 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2388 --- PASS: TestGlobMatch/fo?_fo (0.00s)2389 --- PASS: TestGlobMatch/fo?_foo (0.00s)2390 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2391 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2392 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2393 --- PASS: TestGlobMatch/*/*_foo (0.00s)2394 --- PASS: TestGlobMatch/*bar_bar (0.00s)2395 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2396 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2397 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2398 --- PASS: TestGlobMatch/*bar_foo (0.00s)2399 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2400 --- PASS: TestGlobMatch/foo*_foo (0.00s)2401 --- PASS: TestGlobMatch/foo*_bar (0.00s)2402 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2403 --- PASS: TestGlobMatch/*_ (0.00s)2404 --- PASS: TestGlobMatch/*_anything (0.00s)2405 --- PASS: TestGlobMatch/foo_bar (0.00s)2406--- PASS: TestValidateToken_NoMatchingProvider (0.01s)24072026/09/10 17:37:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50517/oidc2408--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2409--- PASS: TestValidateToken_MultipleProviders (0.01s)2410--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)24112026/09/10 17:37:43 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232412--- PASS: TestValidateToken_ValidToken (0.01s)24132026/09/10 17:37:43 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5051924142026/09/10 17:37:43 http: TLS handshake error from 127.0.0.1:50512: remote error: tls: bad certificate2415--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2416--- PASS: TestScopes_Rules (0.02s)2417--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2418--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2419PASS2420Running hook tests...2421=== RUN TestSendPathsEmpty2422=== PAUSE TestSendPathsEmpty2423=== RUN TestQueueEnqueueAndFetch2424=== PAUSE TestQueueEnqueueAndFetch2425=== RUN TestQueueDeduplication2426=== PAUSE TestQueueDeduplication2427=== RUN TestQueueRemove2428=== PAUSE TestQueueRemove2429=== RUN TestQueueFetchBatchLimit2430=== PAUSE TestQueueFetchBatchLimit2431=== RUN TestQueueRetryMovesToBack2432=== PAUSE TestQueueRetryMovesToBack2433=== RUN TestQueueFetchRemoveLifecycle2434=== PAUSE TestQueueFetchRemoveLifecycle2435=== RUN TestQueueConcurrentWriters2436=== PAUSE TestQueueConcurrentWriters2437=== RUN TestQueueRemoveLargeClosure2438=== PAUSE TestQueueRemoveLargeClosure2439=== RUN TestServerClientIntegration2440=== PAUSE TestServerClientIntegration2441=== RUN TestServerQueueError2442=== PAUSE TestServerQueueError2443=== RUN TestGetListenerSocketActivation2444 server_test.go:213: === RUN TestGetListenerSocketActivation2445 --- PASS: TestGetListenerSocketActivation (0.00s)2446 PASS2447 2448--- PASS: TestGetListenerSocketActivation (0.01s)2449=== RUN TestServerWait2450=== PAUSE TestServerWait2451=== RUN TestDrainIsolatesPoisonPath2452=== PAUSE TestDrainIsolatesPoisonPath2453=== RUN TestRunNotBlockedByPoisonHead2454=== PAUSE TestRunNotBlockedByPoisonHead2455=== RUN TestDrainGivesUpWhenServerDown2456=== PAUSE TestDrainGivesUpWhenServerDown2457=== RUN TestFailedPathPrunedByLaterClosure2458=== PAUSE TestFailedPathPrunedByLaterClosure2459=== RUN TestWorkerUploadsAndRemoves2460=== PAUSE TestWorkerUploadsAndRemoves2461=== RUN TestWorkerSkipsGCdPaths2462=== PAUSE TestWorkerSkipsGCdPaths2463=== RUN TestWorkerPrunesClosureDeps2464=== PAUSE TestWorkerPrunesClosureDeps2465=== RUN TestDrainTimeout2466=== PAUSE TestDrainTimeout2467=== CONT TestSendPathsEmpty2468=== CONT TestServerQueueError2469--- PASS: TestSendPathsEmpty (0.00s)2470=== CONT TestServerClientIntegration2471=== CONT TestFailedPathPrunedByLaterClosure2472=== CONT TestWorkerPrunesClosureDeps2473=== CONT TestDrainTimeout2474=== CONT TestWorkerSkipsGCdPaths2475=== CONT TestQueueConcurrentWriters2476=== CONT TestQueueRemoveLargeClosure2477=== CONT TestRunNotBlockedByPoisonHead2478=== CONT TestDrainGivesUpWhenServerDown24792026/09/10 17:37:43 ERROR Hook request failed error="permission denied" wait=false count=12480--- PASS: TestServerQueueError (0.00s)2481=== CONT TestWorkerUploadsAndRemoves2482--- PASS: TestServerClientIntegration (0.00s)2483=== CONT TestQueueFetchRemoveLifecycle24842026/09/10 17:37:43 INFO Upload queue status pending=224852026/09/10 17:37:43 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-99207-761247270/TestWorkerSkipsGCdPaths2327339279/002/nonexistent24862026/09/10 17:37:43 INFO Upload queue status pending=224872026/09/10 17:37:43 INFO Uploading batch count=224882026/09/10 17:37:43 INFO Uploading batch count=224892026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=224902026/09/10 17:37:43 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99207-761247270/TestDrainGivesUpWhenServerDown2934457150/002/a24912026/09/10 17:37:43 INFO Uploading batch count=22492--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2493=== CONT TestDrainIsolatesPoisonPath24942026/09/10 17:37:43 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99207-761247270/TestDrainGivesUpWhenServerDown2934457150/002/b24952026/09/10 17:37:43 INFO Uploading batch count=124962026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=124972026/09/10 17:37:43 INFO Upload queue status pending=224982026/09/10 17:37:43 INFO Upload queue status pending=324992026/09/10 17:37:43 INFO Uploading batch count=125002026/09/10 17:37:43 INFO Uploading batch count=125012026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=125022026/09/10 17:37:43 INFO Uploading batch count=125032026/09/10 17:37:43 INFO Uploading batch count=225042026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=225052026/09/10 17:37:43 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99207-761247270/TestDrainGivesUpWhenServerDown2934457150/002/c25062026/09/10 17:37:43 INFO Uploading batch count=125072026/09/10 17:37:43 INFO Uploading batch count=125082026/09/10 17:37:43 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99207-761247270/TestDrainGivesUpWhenServerDown2934457150/002/d25092026/09/10 17:37:43 INFO Uploading batch count=225102026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=225112026/09/10 17:37:43 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99207-761247270/TestDrainGivesUpWhenServerDown2934457150/002/e25122026/09/10 17:37:43 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99207-761247270/TestDrainGivesUpWhenServerDown2934457150/002/f25132026/09/10 17:37:43 ERROR Drain finished with paths left in queue remaining=102514--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2515=== CONT TestQueueRemove25162026/09/10 17:37:43 INFO Uploading batch count=425172026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=425182026/09/10 17:37:43 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99207-761247270/TestDrainIsolatesPoisonPath966353585/002/bbb2519--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2520=== CONT TestQueueFetchBatchLimit25212026/09/10 17:37:43 INFO Uploading batch count=125222026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=125232026/09/10 17:37:43 INFO Uploading batch count=125242026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=125252026/09/10 17:37:43 INFO Uploading batch count=125262026/09/10 17:37:43 ERROR Upload failed error="upload failed" count=125272026/09/10 17:37:43 ERROR Drain finished with paths left in queue remaining=12528--- PASS: TestQueueRemove (0.00s)2529=== CONT TestQueueDeduplication2530--- PASS: TestDrainIsolatesPoisonPath (0.01s)2531=== CONT TestQueueEnqueueAndFetch2532--- PASS: TestQueueFetchBatchLimit (0.00s)2533=== CONT TestServerWait25342026/09/10 17:37:43 ERROR Hook request failed error="409 stale claim" wait=true count=12535--- PASS: TestServerWait (0.00s)2536=== CONT TestQueueRetryMovesToBack2537--- PASS: TestQueueDeduplication (0.00s)2538--- PASS: TestQueueEnqueueAndFetch (0.00s)2539--- PASS: TestQueueRetryMovesToBack (0.00s)2540--- PASS: TestWorkerUploadsAndRemoves (0.03s)2541--- PASS: TestWorkerSkipsGCdPaths (0.03s)2542--- PASS: TestWorkerPrunesClosureDeps (0.03s)2543--- PASS: TestQueueRemoveLargeClosure (0.06s)2544--- PASS: TestQueueConcurrentWriters (0.15s)25452026/09/10 17:37:43 ERROR Upload failed error="context deadline exceeded" count=225462026/09/10 17:37:43 ERROR Drain finished with paths left in queue remaining=42547--- PASS: TestDrainTimeout (0.21s)25482026/09/10 17:37:44 INFO Uploading batch count=125492026/09/10 17:37:44 INFO Uploading batch count=125502026/09/10 17:37:44 INFO Uploading batch count=125512026/09/10 17:37:44 ERROR Upload failed error="upload failed" count=125522026/09/10 17:37:44 INFO Uploading batch count=125532026/09/10 17:37:44 ERROR Upload failed error="upload failed" count=125542026/09/10 17:37:44 INFO Uploading batch count=125552026/09/10 17:37:44 ERROR Upload failed error="upload failed" count=125562026/09/10 17:37:44 INFO Uploading batch count=125572026/09/10 17:37:44 ERROR Upload failed error="upload failed" count=125582026/09/10 17:37:44 ERROR Drain finished with paths left in queue remaining=12559--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2560PASS