niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #195
· 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.05s)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 TestStreamPushRequestLine59=== PAUSE TestStreamPushRequestLine60=== RUN TestSetClientTLS61=== PAUSE TestSetClientTLS62=== RUN TestSetClientTLSDoesNotMutateDefaultTransport63=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport64=== RUN TestSetClientTLSErrors65=== PAUSE TestSetClientTLSErrors66=== RUN TestStaticToken67=== PAUSE TestStaticToken68=== RUN TestFileTokenReadsAndCaches69=== PAUSE TestFileTokenReadsAndCaches70=== RUN TestFileTokenMissing71=== PAUSE TestFileTokenMissing72=== RUN TestFileTokenEmpty73=== PAUSE TestFileTokenEmpty74=== RUN TestScriptTokenNoExpiryRerunsEveryCall75=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall76=== RUN TestScriptTokenCachesUntilRefresh77=== PAUSE TestScriptTokenCachesUntilRefresh78=== RUN TestScriptTokenEmptyToken79=== PAUSE TestScriptTokenEmptyToken80=== RUN TestScriptTokenBadJSON81=== PAUSE TestScriptTokenBadJSON82=== RUN TestScriptTokenScriptFails83=== PAUSE TestScriptTokenScriptFails84=== RUN TestScriptTokenEmptyCommand85=== PAUSE TestScriptTokenEmptyCommand86=== CONT TestDoServerRequestAttachesToken87=== CONT TestScriptTokenEmptyCommand88=== CONT TestShellSplit89=== CONT TestStaticToken90--- PASS: TestScriptTokenEmptyCommand (0.00s)91=== CONT TestConvertHashToNix3292=== RUN TestConvertHashToNix32/SRI_format_to_Nix3293=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3294=== RUN TestConvertHashToNix32/already_Nix32_format95=== PAUSE TestConvertHashToNix32/already_Nix32_format96=== RUN TestConvertHashToNix32/invalid_format97--- PASS: TestStaticToken (0.00s)98=== CONT TestScriptTokenScriptFails99=== CONT TestScriptTokenBadJSON100=== CONT TestScriptTokenEmptyToken101=== CONT TestScriptTokenCachesUntilRefresh102=== CONT TestScriptTokenNoExpiryRerunsEveryCall103=== CONT TestFileTokenEmpty104=== CONT TestFileTokenMissing105=== CONT TestFileTokenReadsAndCaches106=== PAUSE TestConvertHashToNix32/invalid_format107--- PASS: TestShellSplit (0.00s)108=== CONT TestStreamPushGivesUpOnDeadServer109=== CONT TestSetClientTLSErrors110=== CONT TestSetClientTLSDoesNotMutateDefaultTransport111--- PASS: TestFileTokenReadsAndCaches (0.00s)1122026/09/10 17:37:23 ERROR Upload failed error="connection refused" count=201132026/09/10 17:37:23 ERROR Server seems unavailable, giving up on batch untried=17114--- PASS: TestFileTokenMissing (0.00s)115--- PASS: TestFileTokenEmpty (0.00s)116=== CONT TestSetClientTLS117--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)118=== CONT TestStreamPushRequestLine119--- PASS: TestScriptTokenScriptFails (0.00s)120=== CONT TestEncodeNixBase32121=== RUN TestEncodeNixBase32/test_string_hash1222026/09/10 17:37:23 ERROR Upload failed error="stale build claim" count=1123=== PAUSE TestEncodeNixBase32/test_string_hash124=== RUN TestEncodeNixBase32/empty_input125=== PAUSE TestEncodeNixBase32/empty_input126=== CONT TestEncodeNixBase32WithRealHash127--- PASS: TestEncodeNixBase32WithRealHash (0.00s)128--- PASS: TestStreamPushRequestLine (0.00s)129=== CONT TestStreamPushBatchesUnderLoad130=== CONT TestStreamPushIsolatesFailures1312026/09/10 17:37:23 ERROR Upload failed error="bad path" count=3132--- PASS: TestStreamPushIsolatesFailures (0.00s)133=== CONT TestPathInfoCACompatibility134--- PASS: TestDoServerRequestAttachesToken (0.01s)135=== RUN TestPathInfoCACompatibility/null_ca_field136=== CONT TestDoWithRetry_BodyReplayedViaGetBody137=== PAUSE TestPathInfoCACompatibility/null_ca_field138=== RUN TestPathInfoCACompatibility/old_string_format_-_text139=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text140=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive141=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive142=== RUN TestPathInfoCACompatibility/new_structured_format_-_text143=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text144=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method145=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method146=== CONT TestResolveStorePath147=== RUN TestSetClientTLSErrors/missing_cert_file148=== PAUSE TestSetClientTLSErrors/missing_cert_file149=== RUN TestSetClientTLSErrors/missing_key_file150=== PAUSE TestSetClientTLSErrors/missing_key_file151=== RUN TestSetClientTLSErrors/missing_ca_file152=== PAUSE TestSetClientTLSErrors/missing_ca_file153=== RUN TestSetClientTLSErrors/invalid_ca_file154=== PAUSE TestSetClientTLSErrors/invalid_ca_file155=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1562026/09/10 17:37:23 WARN Rate limiter enabled after throttle name=server-test rate=51572026/09/10 17:37:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:502141582026/09/10 17:37:23 WARN Rate limiter enabled after throttle name=server-test rate=51592026/09/10 17:37:23 WARN Rate limiter backed off name=server-test rate=51602026/09/10 17:37:23 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:50214161--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)162=== CONT TestRateLimiterFeedback163=== RUN TestRateLimiterFeedback/429_enables_limiter164=== PAUSE TestRateLimiterFeedback/429_enables_limiter165=== RUN TestRateLimiterFeedback/503_enables_limiter166=== PAUSE TestRateLimiterFeedback/503_enables_limiter167=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter168=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter169--- PASS: TestResolveStorePath (0.00s)170=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter171=== CONT TestParsePathInfoJSON172=== RUN TestParsePathInfoJSON/Nix_format173=== PAUSE TestParsePathInfoJSON/Nix_format174=== RUN TestParsePathInfoJSON/Lix_format175=== PAUSE TestParsePathInfoJSON/Lix_format176=== RUN TestParsePathInfoJSON/empty_input177=== PAUSE TestParsePathInfoJSON/empty_input178=== RUN TestParsePathInfoJSON/whitespace_only179=== PAUSE TestParsePathInfoJSON/whitespace_only180=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter181=== RUN TestParsePathInfoJSON/invalid_JSON182=== PAUSE TestParsePathInfoJSON/invalid_JSON183--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)184=== CONT TestStreamPushReportsEveryPath185=== CONT TestParsePathInfoJSONMultiplePaths186=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths187=== CONT TestPartSizeForNAR188=== RUN TestPartSizeForNAR/zero_stays_at_minimum189=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths190=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths191=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths192--- PASS: TestStreamPushReportsEveryPath (0.00s)193=== CONT TestPathInfoHashCompatibility194=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum195=== CONT TestUploadMultipart_SupersededByPeer196=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)197=== RUN TestPartSizeForNAR/small_stays_at_minimum198=== RUN TestUploadMultipart_SupersededByPeer/exists199=== PAUSE TestUploadMultipart_SupersededByPeer/exists200=== PAUSE TestPartSizeForNAR/small_stays_at_minimum201=== RUN TestUploadMultipart_SupersededByPeer/missing202=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum203=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum204=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts205=== PAUSE TestUploadMultipart_SupersededByPeer/missing206=== CONT TestShellSplitErrors207=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)208=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon209=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts210=== RUN TestPartSizeForNAR/1_TiB211=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon212--- PASS: TestShellSplitErrors (0.00s)213=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI214=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI215=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512216=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512217=== CONT TestFilterOversizedClosures218=== RUN TestFilterOversizedClosures/no_limit_keeps_everything219=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything220=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped221=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped222=== CONT TestGetStorePathHash223=== RUN TestGetStorePathHash/valid_store_path224=== RUN TestFilterOversizedClosures/all_closures_skipped225=== PAUSE TestGetStorePathHash/valid_store_path226=== PAUSE TestFilterOversizedClosures/all_closures_skipped227=== PAUSE TestPartSizeForNAR/1_TiB228=== RUN TestPartSizeForNAR/5_TiB_S3_max_object229=== CONT TestCaseHackSuffix230=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object231=== RUN TestSetClientTLS/rejects_connection_without_client_cert232=== RUN TestPartSizeForNAR/capped_at_5_GiB233=== PAUSE TestPartSizeForNAR/capped_at_5_GiB234=== RUN TestGetStorePathHash/basename_without_hyphen_should_error235=== CONT TestDumpPathWriterError236=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert237=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA238=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA239=== RUN TestSetClientTLS/preserves_debug_logging_transport240=== PAUSE TestSetClientTLS/preserves_debug_logging_transport241=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error242=== CONT TestDumpPathSingleFile243=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error244=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error245=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error246=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error247=== CONT TestDumpPathMatchesNix248--- PASS: TestScriptTokenBadJSON (0.01s)249=== CONT TestConvertHashToNix32/SRI_format_to_Nix32250=== CONT TestConvertHashToNix32/invalid_format251=== CONT TestConvertHashToNix32/already_Nix32_format252--- PASS: TestConvertHashToNix32 (0.00s)253 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)254 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)255 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)256=== CONT TestEncodeNixBase32/test_string_hash257=== CONT TestEncodeNixBase32/empty_input258--- PASS: TestEncodeNixBase32 (0.00s)259 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)260 --- PASS: TestEncodeNixBase32/empty_input (0.00s)261=== CONT TestPathInfoCACompatibility/null_ca_field262=== CONT TestPathInfoCACompatibility/new_structured_format_-_text263=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive265=== CONT TestPathInfoCACompatibility/old_string_format_-_text266--- PASS: TestPathInfoCACompatibility (0.00s)267 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)268 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)269 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)270 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)271 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)272=== CONT TestSetClientTLSErrors/missing_cert_file273=== CONT TestSetClientTLSErrors/invalid_ca_file274--- PASS: TestScriptTokenEmptyToken (0.01s)275=== CONT TestSetClientTLSErrors/missing_ca_file276=== CONT TestSetClientTLSErrors/missing_key_file277=== CONT TestRateLimiterFeedback/429_enables_limiter278=== CONT TestParsePathInfoJSON/Nix_format279=== CONT TestParsePathInfoJSON/invalid_JSON280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2812026/09/10 17:37:23 WARN Rate limiter enabled after throttle name=server-test rate=52822026/09/10 17:37:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:502192832026/09/10 17:37:23 WARN Rate limiter backed off name=server-test rate=5284--- PASS: TestSetClientTLSErrors (0.00s)285 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)286 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)287 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)288 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)289=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter290=== CONT TestRateLimiterFeedback/503_enables_limiter291=== CONT TestParsePathInfoJSON/empty_input292=== CONT TestParsePathInfoJSON/whitespace_only293=== CONT TestParsePathInfoJSON/Lix_format294--- PASS: TestParsePathInfoJSON (0.00s)295 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)296 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)297 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)298 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)299 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)300=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths301=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths302--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)303 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)304 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)305=== CONT TestUploadMultipart_SupersededByPeer/exists3062026/09/10 17:37:23 WARN Rate limiter enabled after throttle name=server-test rate=53072026/09/10 17:37:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:502253082026/09/10 17:37:23 WARN Rate limiter backed off name=server-test rate=5309--- PASS: TestRateLimiterFeedback (0.00s)310 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)311 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)312 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)313 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)314=== CONT TestUploadMultipart_SupersededByPeer/missing315=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)316=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512317=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI318=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon319--- PASS: TestPathInfoHashCompatibility (0.00s)320 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)321 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)322 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)323 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)324=== CONT TestFilterOversizedClosures/no_limit_keeps_everything325=== CONT TestFilterOversizedClosures/all_closures_skipped3262026/09/10 17:37:23 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50327=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3282026/09/10 17:37:23 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=2000329--- PASS: TestFilterOversizedClosures (0.00s)330 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)331 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)332 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)333=== CONT TestPartSizeForNAR/zero_stays_at_minimum334=== CONT TestPartSizeForNAR/1_TiB335=== CONT TestPartSizeForNAR/capped_at_5_GiB336=== CONT TestPartSizeForNAR/5_TiB_S3_max_object337=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum338=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts339=== CONT TestPartSizeForNAR/small_stays_at_minimum340--- PASS: TestPartSizeForNAR (0.00s)341 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)342 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)343 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)344 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)345 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)346 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)347 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)348=== CONT TestSetClientTLS/rejects_connection_without_client_cert349--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)350 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)351 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)352=== CONT TestSetClientTLS/preserves_debug_logging_transport353=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA354=== CONT TestGetStorePathHash/valid_store_path355=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error356=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error357=== CONT TestGetStorePathHash/basename_without_hyphen_should_error358--- PASS: TestGetStorePathHash (0.00s)359 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)360 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)361 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)362 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3632026/09/10 17:37:23 http: TLS handshake error from 127.0.0.1:50231: remote error: tls: bad certificate364--- PASS: TestSetClientTLS (0.00s)365 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)366 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)367 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)368--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)369--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)370--- PASS: TestDumpPathWriterError (0.03s)371--- PASS: TestDumpPathSingleFile (0.04s)372--- PASS: TestCaseHackSuffix (0.04s)373--- PASS: TestDumpPathMatchesNix (0.06s)374--- PASS: TestStreamPushBatchesUnderLoad (0.10s)375--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)376PASS377Running server tests...378The files belonging to this database system will be owned by user "_nixbld10".379This user must also own the server process.380381The database cluster will be initialized with locale "C".382The default database encoding has accordingly been set to "SQL_ASCII".383The default text search configuration will be set to "english".384385Data page checksums are enabled.386387creating directory /nix/var/nix/builds/nix-99968-1879214675/postgres468158704/data ... ok388creating subdirectories ... ok389selecting dynamic shared memory implementation ... posix390selecting default "max_connections" ... 100391selecting default "shared_buffers" ... 128MB392selecting default time zone ... UTC393creating configuration files ... ok394running bootstrap script ... ok395performing post-bootstrap initialization ... ok396syncing data to disk ... ok397398initdb: warning: enabling "trust" authentication for local connections399initdb: 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.400401Success. You can now start the database server using:402403 pg_ctl -D /nix/var/nix/builds/nix-99968-1879214675/postgres468158704/data -l logfile start404405/nix/var/nix/builds/nix-99968-1879214675/postgres468158704:5432 - no response4062026-09-10 17:37:25.145 UTC [122] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4072026-09-10 17:37:25.145 UTC [122] LOG: listening on Unix socket "/nix/var/nix/builds/nix-99968-1879214675/postgres468158704/.s.PGSQL.5432"4082026-09-10 17:37:25.147 UTC [129] LOG: database system was shut down at 2026-09-10 17:37:25 UTC4092026-09-10 17:37:25.148 UTC [122] LOG: database system is ready to accept connections410/nix/var/nix/builds/nix-99968-1879214675/postgres468158704:5432 - accepting connections411=== RUN TestService_AuthMiddleware412=== PAUSE TestService_AuthMiddleware413=== RUN TestService_AuthMiddleware_MTLSProxyHeader414=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader415=== RUN TestService_AuthMiddleware_MTLSBoundSubjects416=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects417=== RUN TestService_ReadAuthMiddleware418=== PAUSE TestService_ReadAuthMiddleware419=== RUN TestService_AuthMiddleware_OIDC420=== PAUSE TestService_AuthMiddleware_OIDC421=== RUN TestService_RequireScope_OIDC422=== PAUSE TestService_RequireScope_OIDC423=== RUN TestService_ReadScope_PublicByDefault424=== PAUSE TestService_ReadScope_PublicByDefault425=== RUN TestCacheConfigHandler426=== PAUSE TestCacheConfigHandler427=== RUN TestCacheStatsHandler428=== PAUSE TestCacheStatsHandler429=== RUN TestClaim_BuildWaitComplete430=== PAUSE TestClaim_BuildWaitComplete431=== RUN TestClaim_GCMarkedOutputCountsAsAbsent432=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent433=== RUN TestClaim_TooManyStreams434=== PAUSE TestClaim_TooManyStreams435=== RUN TestClaim_HolderDisconnectKeepsClaim436=== PAUSE TestClaim_HolderDisconnectKeepsClaim437=== RUN TestClaim_FailWakesWaitersButIsNotRemembered438=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered439=== RUN TestClaim_FailWithoutKindReleases440=== PAUSE TestClaim_FailWithoutKindReleases441=== RUN TestClaim_StaleHeartbeatStolen442=== PAUSE TestClaim_StaleHeartbeatStolen443=== RUN TestClaim_TwoInstances444=== PAUSE TestClaim_TwoInstances445=== RUN TestClaim_InputsTouched446=== PAUSE TestClaim_InputsTouched447=== RUN TestClaim_StreamsThroughServer448=== PAUSE TestClaim_StreamsThroughServer449=== RUN TestClientCADerivations450=== PAUSE TestClientCADerivations451=== RUN TestClientErrorHandling452=== PAUSE TestClientErrorHandling453=== RUN TestClientIntegration454=== PAUSE TestClientIntegration455=== RUN TestClientMultipleUploads456=== PAUSE TestClientMultipleUploads457=== RUN TestClientWithDependencies458=== PAUSE TestClientWithDependencies459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestResolveDBConnectionString462=== PAUSE TestResolveDBConnectionString463=== RUN TestGCAdvisoryLockBlocksConcurrentRun4642026-09-10 17:37:25.434 UTC [201] ERROR: relation "goose_db_version" does not exist at character 364652026-09-10 17:37:25.434 UTC [201] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4662026/09/10 17:37:25 OK 20241026095416_initial_model.sql (3.14ms)4672026/09/10 17:37:25 OK 20251210153512_drop_unused_gin_index.sql (372.13µs)4682026/09/10 17:37:25 OK 20251218171726_add_pins.sql (736.13µs)4692026/09/10 17:37:25 OK 20260628120000_add_object_size_and_stats.sql (753µs)4702026/09/10 17:37:25 OK 20260905000000_add_claims.sql (881.5µs)4712026/09/10 17:37:25 goose: successfully migrated database to version: 202609050000004722026/09/10 17:37:25 OK 1_commit_pending_closure.sql (833.79µs)4732026/09/10 17:37:25 OK 2_object_stats_trigger.sql (207.83µs)4742026/09/10 17:37:25 goose: up to current file version: 2475--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.18s)476=== RUN TestGCBugBareHashReferences477=== PAUSE TestGCBugBareHashReferences478=== RUN TestGCMetrics479=== PAUSE TestGCMetrics480=== RUN TestGCTaskStore_StartNew481=== PAUSE TestGCTaskStore_StartNew482=== RUN TestGCTaskStore_DeduplicateSameParams483=== PAUSE TestGCTaskStore_DeduplicateSameParams484=== RUN TestGCTaskStore_ConflictDifferentParams485=== PAUSE TestGCTaskStore_ConflictDifferentParams486=== RUN TestGCTaskStore_GetEmpty487=== PAUSE TestGCTaskStore_GetEmpty488=== RUN TestGCTaskStore_GetReturnsLatest489=== PAUSE TestGCTaskStore_GetReturnsLatest490=== RUN TestGCTaskStore_CompletedAllowsNewTask491=== PAUSE TestGCTaskStore_CompletedAllowsNewTask492=== RUN TestGCTaskStore_PhaseUpdates493=== PAUSE TestGCTaskStore_PhaseUpdates494=== RUN TestGCTaskStore_Fail495=== PAUSE TestGCTaskStore_Fail496=== RUN TestGracefulShutdownDrainsInflight497=== PAUSE TestGracefulShutdownDrainsInflight498=== RUN TestService_healthCheckHandler499=== PAUSE TestService_healthCheckHandler500=== RUN TestService_readinessHandler501=== PAUSE TestService_readinessHandler502=== RUN TestGenerateLandingPage503=== PAUSE TestGenerateLandingPage504=== RUN TestCacheConfigHandlerMaxNarSize505=== PAUSE TestCacheConfigHandlerMaxNarSize506=== RUN TestCreatePendingClosureRejectsOversizedNAR507=== PAUSE TestCreatePendingClosureRejectsOversizedNAR508=== RUN TestNARDeduplicationMetadataUploadBug509=== PAUSE TestNARDeduplicationMetadataUploadBug510=== RUN TestMetricsInventory511=== PAUSE TestMetricsInventory512=== RUN TestService_NativeMTLS513=== PAUSE TestService_NativeMTLS514=== RUN TestServerTLSConfig515=== PAUSE TestServerTLSConfig516=== RUN TestMultipartCleanup517=== PAUSE TestMultipartCleanup518=== RUN TestObjectStatsTrigger519=== PAUSE TestObjectStatsTrigger520=== RUN TestOrphanedObjectsGC521=== PAUSE TestOrphanedObjectsGC522=== RUN TestOrphanedObjectsGCStressTest523=== PAUSE TestOrphanedObjectsGCStressTest524=== RUN TestResurrectedObjectNotDeleted525=== PAUSE TestResurrectedObjectNotDeleted526=== RUN TestParseSingleRange527=== PAUSE TestParseSingleRange528=== RUN TestIsValidCachePath529=== PAUSE TestIsValidCachePath530=== RUN TestReadProxyNarinfo531=== PAUSE TestReadProxyNarinfo532=== RUN TestReadProxyNarinfoAlreadyDecompressed533=== PAUSE TestReadProxyNarinfoAlreadyDecompressed534=== RUN TestReadProxyNarStreaming535=== PAUSE TestReadProxyNarStreaming536=== RUN TestReadProxy404537=== PAUSE TestReadProxy404538=== RUN TestReadProxyInvalidPath539=== PAUSE TestReadProxyInvalidPath540=== RUN TestReadProxyHead541=== PAUSE TestReadProxyHead542=== RUN TestReadProxyConditionalGet543=== PAUSE TestReadProxyConditionalGet544=== RUN TestReadProxyRootRedirectsToIndexHTML545=== PAUSE TestReadProxyRootRedirectsToIndexHTML546=== RUN TestReadProxyDisabled547=== PAUSE TestReadProxyDisabled548=== RUN TestReadRedirectNar549=== PAUSE TestReadRedirectNar550=== RUN TestReadRedirectKeepsNarinfoProxied551=== PAUSE TestReadRedirectKeepsNarinfoProxied552=== RUN TestReadProxyRangeRequest553=== PAUSE TestReadProxyRangeRequest554=== RUN TestReadRedirectUsesPublicS3URL555=== PAUSE TestReadRedirectUsesPublicS3URL556=== RUN TestRedundantMultipartUpload557=== PAUSE TestRedundantMultipartUpload558=== RUN TestCompleteMultipartUpload_ErrorButObjectExists559=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists560=== RUN TestCompletedNarNotReofferedAcrossClosures561=== PAUSE TestCompletedNarNotReofferedAcrossClosures562=== RUN TestPresignedUploadRegisteredBeforeCommit563=== PAUSE TestPresignedUploadRegisteredBeforeCommit564=== RUN TestService_Rustfstest565=== PAUSE TestService_Rustfstest566=== RUN TestParseSize567=== PAUSE TestParseSize568=== RUN TestSkippedUploadsHandler569=== PAUSE TestSkippedUploadsHandler570=== RUN TestSystemdListenerNotActivated571--- PASS: TestSystemdListenerNotActivated (0.00s)572=== RUN TestWatchdogBeatsWhenHealthy573--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)574=== RUN TestWatchdogSkipsWhenUnhealthy5752026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5812026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5822026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5832026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5842026/09/10 17:37:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"585--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)586=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle587=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle588=== RUN TestProxyWriteTimeout589=== PAUSE TestProxyWriteTimeout590=== RUN TestIsValidUploadKey591=== PAUSE TestIsValidUploadKey592=== RUN TestUploadHandlersRejectInvalidKeys593=== PAUSE TestUploadHandlersRejectInvalidKeys594=== RUN TestUploadHandlersRejectOversizedBody595=== PAUSE TestUploadHandlersRejectOversizedBody596=== RUN TestService_cleanupPendingClosuresHandler597=== PAUSE TestService_cleanupPendingClosuresHandler598=== RUN TestService_createPendingClosureHandler599=== PAUSE TestService_createPendingClosureHandler600=== RUN TestService_verifyS3Integrity601=== PAUSE TestService_verifyS3Integrity602=== RUN TestCompleteMultipartUnregistered603=== PAUSE TestCompleteMultipartUnregistered604=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT605=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT606=== CONT TestReadProxyDisabled607=== CONT TestService_AuthMiddleware608=== CONT TestSkippedUploadsHandler609=== CONT TestGCTaskStore_GetEmpty610--- PASS: TestGCTaskStore_GetEmpty (0.00s)611=== CONT TestServerTLSConfig612=== RUN TestServerTLSConfig/no_client_CA613=== PAUSE TestServerTLSConfig/no_client_CA614=== CONT TestReadProxyRootRedirectsToIndexHTML615=== RUN TestServerTLSConfig/missing_CA_file616=== PAUSE TestServerTLSConfig/missing_CA_file617=== RUN TestServerTLSConfig/not_a_PEM_file618=== PAUSE TestServerTLSConfig/not_a_PEM_file619=== CONT TestServerTLSConfig/no_client_CA620=== CONT TestService_NativeMTLS621=== CONT TestService_cleanupPendingClosuresHandler622=== CONT TestReadProxyConditionalGet623=== CONT TestMetricsInventory624=== CONT TestParseSize625--- PASS: TestParseSize (0.00s)626=== CONT TestMultipartCleanup627=== CONT TestService_Rustfstest6282026/09/10 17:37:25 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000629--- PASS: TestSkippedUploadsHandler (0.01s)630=== CONT TestPresignedUploadRegisteredBeforeCommit6312026-09-10 17:37:26.087 UTC [225] ERROR: relation "goose_db_version" does not exist at character 366322026-09-10 17:37:26.087 UTC [225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6332026-09-10 17:37:26.105 UTC [226] ERROR: relation "goose_db_version" does not exist at character 366342026-09-10 17:37:26.105 UTC [226] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6352026-09-10 17:37:26.110 UTC [227] ERROR: relation "goose_db_version" does not exist at character 366362026-09-10 17:37:26.110 UTC [227] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6372026-09-10 17:37:26.110 UTC [230] ERROR: relation "goose_db_version" does not exist at character 366382026-09-10 17:37:26.110 UTC [230] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6392026-09-10 17:37:26.111 UTC [228] ERROR: relation "goose_db_version" does not exist at character 366402026-09-10 17:37:26.111 UTC [228] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026-09-10 17:37:26.112 UTC [231] ERROR: relation "goose_db_version" does not exist at character 366422026-09-10 17:37:26.112 UTC [231] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6432026/09/10 17:37:26 OK 20241026095416_initial_model.sql (6.95ms)6442026-09-10 17:37:26.113 UTC [229] ERROR: relation "goose_db_version" does not exist at character 366452026-09-10 17:37:26.113 UTC [229] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6462026-09-10 17:37:26.113 UTC [234] ERROR: relation "goose_db_version" does not exist at character 366472026-09-10 17:37:26.113 UTC [234] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6482026-09-10 17:37:26.113 UTC [232] ERROR: relation "goose_db_version" does not exist at character 366492026-09-10 17:37:26.113 UTC [232] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026-09-10 17:37:26.114 UTC [233] ERROR: relation "goose_db_version" does not exist at character 366512026-09-10 17:37:26.114 UTC [233] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (4ms)6532026/09/10 17:37:26 OK 20251218171726_add_pins.sql (1.97ms)6542026/09/10 17:37:26 OK 20241026095416_initial_model.sql (10.93ms)6552026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (2.12ms)6562026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (986.13µs)6572026/09/10 17:37:26 OK 20241026095416_initial_model.sql (9.15ms)6582026/09/10 17:37:26 OK 20251218171726_add_pins.sql (1.12ms)6592026/09/10 17:37:26 OK 20260905000000_add_claims.sql (2.28ms)6602026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000006612026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)6622026/09/10 17:37:26 OK 20241026095416_initial_model.sql (10.61ms)6632026/09/10 17:37:26 OK 20251218171726_add_pins.sql (1.17ms)6642026/09/10 17:37:26 OK 20241026095416_initial_model.sql (6.56ms)6652026/09/10 17:37:26 OK 1_commit_pending_closure.sql (1.48ms)6662026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (920.54µs)6672026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (2.26ms)6682026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (584.5µs)6692026/09/10 17:37:26 OK 2_object_stats_trigger.sql (532.29µs)6702026/09/10 17:37:26 goose: up to current file version: 26712026/09/10 17:37:26 OK 20241026095416_initial_model.sql (6.91ms)6722026/09/10 17:37:26 OK 20241026095416_initial_model.sql (7.44ms)6732026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)6742026/09/10 17:37:26 OK 20241026095416_initial_model.sql (7.7ms)6752026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (748.83µs)6762026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (634.29µs)6772026/09/10 17:37:26 OK 20251218171726_add_pins.sql (1.71ms)6782026/09/10 17:37:26 OK 20251218171726_add_pins.sql (1.68ms)6792026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (914.13µs)6802026/09/10 17:37:26 OK 20241026095416_initial_model.sql (8.98ms)6812026/09/10 17:37:26 OK 20241026095416_initial_model.sql (8.66ms)6822026/09/10 17:37:26 OK 20260905000000_add_claims.sql (2.46ms)6832026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000006842026/09/10 17:37:26 OK 20251218171726_add_pins.sql (1.39ms)6852026/09/10 17:37:26 OK 20251218171726_add_pins.sql (1.45ms)6862026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (666.04µs)6872026/09/10 17:37:26 OK 20260905000000_add_claims.sql (1.88ms)6882026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000006892026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (1.41ms)6902026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (969.71µs)6912026/09/10 17:37:26 OK 1_commit_pending_closure.sql (1.34ms)6922026/09/10 17:37:26 OK 1_commit_pending_closure.sql (930.08µs)6932026/09/10 17:37:26 OK 2_object_stats_trigger.sql (215.75µs)6942026/09/10 17:37:26 goose: up to current file version: 26952026/09/10 17:37:26 OK 2_object_stats_trigger.sql (226.25µs)6962026/09/10 17:37:26 goose: up to current file version: 26972026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (8.66ms)6982026/09/10 17:37:26 OK 20251218171726_add_pins.sql (8.51ms)6992026/09/10 17:37:26 OK 20251218171726_add_pins.sql (7.87ms)7002026/09/10 17:37:26 OK 20251218171726_add_pins.sql (8.18ms)7012026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (13.1ms)7022026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (10.49ms)7032026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (18.79ms)7042026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (10.81ms)7052026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (11.34ms)7062026/09/10 17:37:26 OK 20260905000000_add_claims.sql (19.81ms)7072026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007082026/09/10 17:37:26 OK 20260905000000_add_claims.sql (12.33ms)7092026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007102026/09/10 17:37:26 OK 20260905000000_add_claims.sql (13.23ms)7112026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007122026/09/10 17:37:26 OK 1_commit_pending_closure.sql (6.44ms)7132026/09/10 17:37:26 OK 1_commit_pending_closure.sql (6.65ms)7142026/09/10 17:37:26 OK 2_object_stats_trigger.sql (381.71µs)7152026/09/10 17:37:26 goose: up to current file version: 27162026/09/10 17:37:26 OK 2_object_stats_trigger.sql (263.92µs)7172026/09/10 17:37:26 goose: up to current file version: 27182026/09/10 17:37:26 OK 1_commit_pending_closure.sql (1.11ms)7192026/09/10 17:37:26 OK 2_object_stats_trigger.sql (184.29µs)7202026/09/10 17:37:26 goose: up to current file version: 27212026/09/10 17:37:26 OK 20260905000000_add_claims.sql (15.23ms)7222026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007232026/09/10 17:37:26 OK 20260905000000_add_claims.sql (15.22ms)7242026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007252026/09/10 17:37:26 OK 20260905000000_add_claims.sql (15.66ms)7262026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007272026/09/10 17:37:26 OK 20260905000000_add_claims.sql (15.97ms)7282026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007292026/09/10 17:37:26 OK 1_commit_pending_closure.sql (856.46µs)7302026/09/10 17:37:26 OK 1_commit_pending_closure.sql (862.29µs)7312026/09/10 17:37:26 OK 1_commit_pending_closure.sql (734.33µs)7322026/09/10 17:37:26 OK 2_object_stats_trigger.sql (207.79µs)7332026/09/10 17:37:26 goose: up to current file version: 27342026/09/10 17:37:26 OK 1_commit_pending_closure.sql (1.14ms)7352026/09/10 17:37:26 OK 2_object_stats_trigger.sql (219.92µs)7362026/09/10 17:37:26 goose: up to current file version: 27372026/09/10 17:37:26 OK 2_object_stats_trigger.sql (214.25µs)7382026/09/10 17:37:26 goose: up to current file version: 27392026/09/10 17:37:26 OK 2_object_stats_trigger.sql (185.54µs)7402026/09/10 17:37:26 goose: up to current file version: 27412026/09/10 17:37:26 INFO Received uploads request method=POST path=/api/pending_closures7422026/09/10 17:37:26 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7432026/09/10 17:37:26 INFO Received uploads request method=POST path=/api/pending_closures744--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.44s)745=== CONT TestCompletedNarNotReofferedAcrossClosures7462026/09/10 17:37:26 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"747--- PASS: TestService_AuthMiddleware (0.56s)748=== CONT TestCompleteMultipartUpload_ErrorButObjectExists749--- PASS: TestReadProxyConditionalGet (0.71s)750=== CONT TestRedundantMultipartUpload7512026/09/10 17:37:26 INFO Received uploads request method=POST path=/api/pending_closures7522026/09/10 17:37:26 INFO Received cleanup request method=DELETE path=/api/pending_closures7532026/09/10 17:37:26 INFO Aborted multipart uploads count=1754--- PASS: TestMetricsInventory (1.00s)755=== CONT TestReadRedirectUsesPublicS3URL756--- PASS: TestMultipartCleanup (1.00s)757=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT7582026-09-10 17:37:26.786 UTC [252] ERROR: relation "goose_db_version" does not exist at character 367592026-09-10 17:37:26.786 UTC [252] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7602026/09/10 17:37:26 OK 20241026095416_initial_model.sql (61.17ms)7612026-09-10 17:37:26.883 UTC [263] ERROR: relation "goose_db_version" does not exist at character 367622026-09-10 17:37:26.883 UTC [263] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (10.73ms)764--- PASS: TestReadProxyDisabled (1.14s)765=== CONT TestCompleteMultipartUnregistered7662026/09/10 17:37:26 OK 20251218171726_add_pins.sql (18.1ms)7672026/09/10 17:37:26 OK 20260628120000_add_object_size_and_stats.sql (8.77ms)7682026/09/10 17:37:26 OK 20260905000000_add_claims.sql (28.33ms)7692026/09/10 17:37:26 goose: successfully migrated database to version: 202609050000007702026/09/10 17:37:26 OK 1_commit_pending_closure.sql (3.51ms)7712026/09/10 17:37:26 OK 2_object_stats_trigger.sql (560.38µs)7722026/09/10 17:37:26 goose: up to current file version: 27732026/09/10 17:37:26 OK 20241026095416_initial_model.sql (65.97ms)7742026/09/10 17:37:26 OK 20251210153512_drop_unused_gin_index.sql (4.77ms)7752026/09/10 17:37:26 OK 20251218171726_add_pins.sql (12.05ms)7762026-09-10 17:37:27.003 UTC [273] ERROR: relation "goose_db_version" does not exist at character 367772026-09-10 17:37:27.003 UTC [273] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7782026/09/10 17:37:27 OK 20260628120000_add_object_size_and_stats.sql (8.81ms)7792026/09/10 17:37:27 OK 20260905000000_add_claims.sql (29.38ms)7802026/09/10 17:37:27 goose: successfully migrated database to version: 202609050000007812026/09/10 17:37:27 OK 1_commit_pending_closure.sql (4.04ms)7822026/09/10 17:37:27 OK 2_object_stats_trigger.sql (1.36ms)7832026/09/10 17:37:27 goose: up to current file version: 2784--- PASS: TestService_Rustfstest (1.29s)785=== CONT TestService_verifyS3Integrity7862026/09/10 17:37:27 OK 20241026095416_initial_model.sql (59.13ms)7872026/09/10 17:37:27 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)7882026/09/10 17:37:27 OK 20251218171726_add_pins.sql (11.49ms)7892026/09/10 17:37:27 OK 20260628120000_add_object_size_and_stats.sql (43.79ms)7902026/09/10 17:37:27 OK 20260905000000_add_claims.sql (26.58ms)7912026/09/10 17:37:27 goose: successfully migrated database to version: 202609050000007922026/09/10 17:37:27 OK 1_commit_pending_closure.sql (8.61ms)7932026/09/10 17:37:27 OK 2_object_stats_trigger.sql (711.96µs)7942026/09/10 17:37:27 goose: up to current file version: 27952026/09/10 17:37:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7962026/09/10 17:37:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"797--- PASS: TestService_NativeMTLS (1.45s)798=== CONT TestService_createPendingClosureHandler7992026-09-10 17:37:27.430 UTC [301] ERROR: relation "goose_db_version" does not exist at character 368002026-09-10 17:37:27.430 UTC [301] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/09/10 17:37:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8022026/09/10 17:37:27 INFO Aborted multipart uploads count=08032026/09/10 17:37:27 INFO Received uploads request method=POST path=/api/pending_closures8042026-09-10 17:37:27.465 UTC [319] ERROR: relation "goose_db_version" does not exist at character 368052026-09-10 17:37:27.465 UTC [319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8062026/09/10 17:37:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8072026/09/10 17:37:27 INFO Aborted multipart uploads count=18082026/09/10 17:37:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8092026-09-10 17:37:27.512 UTC [229] ERROR: Closure does not exist: id=18102026-09-10 17:37:27.512 UTC [229] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8112026-09-10 17:37:27.512 UTC [229] STATEMENT: -- name: CommitPendingClosure :exec812 SELECT commit_pending_closure($1::bigint)813 814--- PASS: TestService_cleanupPendingClosuresHandler (1.74s)815=== CONT TestGracefulShutdownDrainsInflight8162026/09/10 17:37:27 INFO Starting HTTP server address=127.0.0.1:502848172026/09/10 17:37:27 INFO Shutdown signal received, draining in-flight requests timeout=10s818--- PASS: TestGracefulShutdownDrainsInflight (0.07s)819=== CONT TestNARDeduplicationMetadataUploadBug8202026/09/10 17:37:27 OK 20241026095416_initial_model.sql (125.21ms)8212026/09/10 17:37:27 OK 20251210153512_drop_unused_gin_index.sql (15.37ms)8222026/09/10 17:37:27 OK 20241026095416_initial_model.sql (115.49ms)8232026/09/10 17:37:27 OK 20251210153512_drop_unused_gin_index.sql (12.87ms)8242026/09/10 17:37:27 OK 20251218171726_add_pins.sql (22.34ms)8252026/09/10 17:37:27 OK 20251218171726_add_pins.sql (16.3ms)8262026/09/10 17:37:27 OK 20260628120000_add_object_size_and_stats.sql (21.17ms)8272026/09/10 17:37:27 OK 20260628120000_add_object_size_and_stats.sql (24.12ms)8282026/09/10 17:37:27 OK 20260905000000_add_claims.sql (21.66ms)8292026/09/10 17:37:27 goose: successfully migrated database to version: 202609050000008302026/09/10 17:37:27 OK 1_commit_pending_closure.sql (5.77ms)8312026/09/10 17:37:27 OK 20260905000000_add_claims.sql (9.79ms)8322026/09/10 17:37:27 goose: successfully migrated database to version: 20260905000000833--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.92s)834=== CONT TestCreatePendingClosureRejectsOversizedNAR8352026/09/10 17:37:27 INFO Received uploads request method=POST path=/api/pending_closures836--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)837=== CONT TestCacheConfigHandlerMaxNarSize838--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)839=== CONT TestGenerateLandingPage8402026/09/10 17:37:27 OK 2_object_stats_trigger.sql (1.49ms)8412026/09/10 17:37:27 goose: up to current file version: 28422026/09/10 17:37:27 OK 1_commit_pending_closure.sql (4.58ms)843--- PASS: TestGenerateLandingPage (0.00s)844=== CONT TestService_readinessHandler8452026/09/10 17:37:27 OK 2_object_stats_trigger.sql (613.21µs)8462026/09/10 17:37:27 goose: up to current file version: 28472026-09-10 17:37:27.879 UTC [341] ERROR: relation "goose_db_version" does not exist at character 368482026-09-10 17:37:27.879 UTC [341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8492026/09/10 17:37:27 INFO Received uploads request method=POST path=/api/pending_closures8502026/09/10 17:37:28 OK 20241026095416_initial_model.sql (108.49ms)8512026/09/10 17:37:28 OK 20251210153512_drop_unused_gin_index.sql (13.76ms)8522026/09/10 17:37:28 OK 20251218171726_add_pins.sql (33.53ms)8532026/09/10 17:37:28 OK 20260628120000_add_object_size_and_stats.sql (89.67ms)8542026/09/10 17:37:28 INFO Received uploads request method=POST path=/api/pending_closures8552026/09/10 17:37:28 OK 20260905000000_add_claims.sql (97.8ms)8562026/09/10 17:37:28 goose: successfully migrated database to version: 202609050000008572026/09/10 17:37:28 OK 1_commit_pending_closure.sql (13.34ms)8582026/09/10 17:37:28 OK 2_object_stats_trigger.sql (1.27ms)8592026/09/10 17:37:28 goose: up to current file version: 28602026/09/10 17:37:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8612026/09/10 17:37:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjVhMDgxOWE5LWJkNjEtNGJhZi05ZjUxLWI1MzBiMTUwNmViYngxNzg5MDYxODQ4MjM5NDc1MDAw8622026/09/10 17:37:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjVhMDgxOWE5LWJkNjEtNGJhZi05ZjUxLWI1MzBiMTUwNmViYngxNzg5MDYxODQ4MjM5NDc1MDAw parts=1863--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.15s)864=== CONT TestService_healthCheckHandler8652026/09/10 17:37:28 INFO Received uploads request method=POST path=/api/pending_closures8662026/09/10 17:37:28 INFO Received uploads request method=POST path=/api/pending_closures8672026-09-10 17:37:28.576 UTC [348] ERROR: relation "goose_db_version" does not exist at character 368682026-09-10 17:37:28.576 UTC [348] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8692026-09-10 17:37:28.746 UTC [354] ERROR: relation "goose_db_version" does not exist at character 368702026-09-10 17:37:28.746 UTC [354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC871--- PASS: TestReadRedirectUsesPublicS3URL (2.04s)872=== CONT TestIsValidUploadKey873=== RUN TestIsValidUploadKey/narinfo874=== PAUSE TestIsValidUploadKey/narinfo875=== RUN TestIsValidUploadKey/nar_zst876=== PAUSE TestIsValidUploadKey/nar_zst877=== RUN TestIsValidUploadKey/nar_xz878=== PAUSE TestIsValidUploadKey/nar_xz879=== RUN TestIsValidUploadKey/nar_plain880=== PAUSE TestIsValidUploadKey/nar_plain881=== RUN TestIsValidUploadKey/listing882=== PAUSE TestIsValidUploadKey/listing883=== RUN TestIsValidUploadKey/build_log884=== PAUSE TestIsValidUploadKey/build_log885=== RUN TestIsValidUploadKey/build_log_home-manager_file886=== PAUSE TestIsValidUploadKey/build_log_home-manager_file887=== RUN TestIsValidUploadKey/build_log_plus_in_name888=== PAUSE TestIsValidUploadKey/build_log_plus_in_name889=== RUN TestIsValidUploadKey/build_log_question_mark890=== PAUSE TestIsValidUploadKey/build_log_question_mark891=== RUN TestIsValidUploadKey/build_log_equals892=== PAUSE TestIsValidUploadKey/build_log_equals893=== RUN TestIsValidUploadKey/realisation894=== PAUSE TestIsValidUploadKey/realisation895=== RUN TestIsValidUploadKey/realisation_plus_in_output896=== PAUSE TestIsValidUploadKey/realisation_plus_in_output897=== RUN TestIsValidUploadKey/nix-cache-info898=== PAUSE TestIsValidUploadKey/nix-cache-info899=== RUN TestIsValidUploadKey/index.html900=== PAUSE TestIsValidUploadKey/index.html901=== RUN TestIsValidUploadKey/narinfo_key,_nar_type902=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type903=== RUN TestIsValidUploadKey/nar_key,_narinfo_type904=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type905=== RUN TestIsValidUploadKey/listing_key,_narinfo_type906=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type907=== RUN TestIsValidUploadKey/traversal908=== PAUSE TestIsValidUploadKey/traversal909=== RUN TestIsValidUploadKey/traversal_nar910=== PAUSE TestIsValidUploadKey/traversal_nar911=== RUN TestIsValidUploadKey/absolute912=== PAUSE TestIsValidUploadKey/absolute913=== RUN TestIsValidUploadKey/empty_key914=== PAUSE TestIsValidUploadKey/empty_key915=== RUN TestIsValidUploadKey/unknown_type916=== PAUSE TestIsValidUploadKey/unknown_type917=== CONT TestUploadHandlersRejectOversizedBody9182026/09/10 17:37:28 OK 20241026095416_initial_model.sql (169.67ms)9192026/09/10 17:37:28 OK 20251210153512_drop_unused_gin_index.sql (8.97ms)920=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure921=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure922=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart923=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart924=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts925=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts926=== CONT TestUploadHandlersRejectInvalidKeys927=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info928=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info929=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal930=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal931=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key932=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key933=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key934=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key935=== CONT TestProxyWriteTimeout936=== RUN TestProxyWriteTimeout/narinfo937=== PAUSE TestProxyWriteTimeout/narinfo938=== RUN TestProxyWriteTimeout/1_GiB_nar939=== PAUSE TestProxyWriteTimeout/1_GiB_nar940=== RUN TestProxyWriteTimeout/10_GiB_nar941=== PAUSE TestProxyWriteTimeout/10_GiB_nar942=== RUN TestProxyWriteTimeout/unknown_size943=== PAUSE TestProxyWriteTimeout/unknown_size944=== CONT TestGCTaskStore_GetReturnsLatest945--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)946=== CONT TestGCTaskStore_Fail947--- PASS: TestGCTaskStore_Fail (0.00s)948=== CONT TestGCTaskStore_PhaseUpdates949--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)950=== CONT TestGCTaskStore_CompletedAllowsNewTask951--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)952=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9532026/09/10 17:37:28 OK 20251218171726_add_pins.sql (26.47ms)9542026/09/10 17:37:28 OK 20260628120000_add_object_size_and_stats.sql (40.39ms)9552026/09/10 17:37:28 OK 20260905000000_add_claims.sql (73.18ms)9562026/09/10 17:37:28 goose: successfully migrated database to version: 202609050000009572026/09/10 17:37:28 OK 1_commit_pending_closure.sql (5.72ms)9582026/09/10 17:37:28 OK 2_object_stats_trigger.sql (331µs)9592026/09/10 17:37:28 goose: up to current file version: 29602026/09/10 17:37:29 OK 20241026095416_initial_model.sql (196.6ms)9612026/09/10 17:37:29 OK 20251210153512_drop_unused_gin_index.sql (13.11ms)9622026/09/10 17:37:29 OK 20251218171726_add_pins.sql (28.55ms)9632026/09/10 17:37:29 INFO Received uploads request method=POST path=/api/pending_closures9642026/09/10 17:37:29 OK 20260628120000_add_object_size_and_stats.sql (40.05ms)965--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.39s)966=== CONT TestReadRedirectKeepsNarinfoProxied9672026/09/10 17:37:29 OK 20260905000000_add_claims.sql (71.51ms)9682026/09/10 17:37:29 goose: successfully migrated database to version: 202609050000009692026/09/10 17:37:29 OK 1_commit_pending_closure.sql (4.52ms)9702026/09/10 17:37:29 OK 2_object_stats_trigger.sql (975.5µs)9712026/09/10 17:37:29 goose: up to current file version: 29722026-09-10 17:37:29.282 UTC [359] ERROR: relation "goose_db_version" does not exist at character 369732026-09-10 17:37:29.282 UTC [359] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9742026/09/10 17:37:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9752026/09/10 17:37:29 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst976--- PASS: TestCompleteMultipartUnregistered (2.47s)977=== CONT TestReadProxyRangeRequest9782026-09-10 17:37:29.501 UTC [362] ERROR: relation "goose_db_version" does not exist at character 369792026-09-10 17:37:29.501 UTC [362] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9802026/09/10 17:37:29 OK 20241026095416_initial_model.sql (196.4ms)9812026/09/10 17:37:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9822026/09/10 17:37:29 OK 20251210153512_drop_unused_gin_index.sql (11.06ms)9832026/09/10 17:37:29 OK 20251218171726_add_pins.sql (38.98ms)9842026/09/10 17:37:29 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjNhNzY1MGQ5LWFjZGItNDRmYS1hZTAxLWQ4MTY1Yzc4NTMxYXgxNzg5MDYxODQ3OTM4NDk2MDAw parts=129852026/09/10 17:37:29 INFO Received uploads request method=POST path=/api/pending_closures986--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.38s)987=== CONT TestReadRedirectNar9882026/09/10 17:37:29 OK 20260628120000_add_object_size_and_stats.sql (26.47ms)9892026/09/10 17:37:29 OK 20260905000000_add_claims.sql (41.88ms)9902026/09/10 17:37:29 goose: successfully migrated database to version: 202609050000009912026/09/10 17:37:29 OK 1_commit_pending_closure.sql (7.79ms)9922026/09/10 17:37:29 OK 2_object_stats_trigger.sql (382.29µs)9932026/09/10 17:37:29 goose: up to current file version: 29942026/09/10 17:37:29 INFO Received uploads request method=POST path=/api/pending_closures9952026/09/10 17:37:29 OK 20241026095416_initial_model.sql (140.63ms)9962026/09/10 17:37:29 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)9972026/09/10 17:37:29 OK 20251218171726_add_pins.sql (46.54ms)9982026/09/10 17:37:29 OK 20260628120000_add_object_size_and_stats.sql (26.43ms)9992026/09/10 17:37:29 OK 20260905000000_add_claims.sql (54.54ms)10002026/09/10 17:37:29 goose: successfully migrated database to version: 2026090500000010012026/09/10 17:37:29 OK 1_commit_pending_closure.sql (8.37ms)10022026/09/10 17:37:29 OK 2_object_stats_trigger.sql (588.83µs)10032026/09/10 17:37:29 goose: up to current file version: 210042026/09/10 17:37:29 INFO Received uploads request method=POST path=/api/pending_closures10052026/09/10 17:37:29 INFO Received uploads request method=POST path=/api/pending_closures10062026/09/10 17:37:29 INFO Received uploads request method=POST path=/api/pending_closures10072026/09/10 17:37:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10082026/09/10 17:37:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjEyNzY3NjA5LTZiNzQtNGM1Ni1hZTJhLWJiZGE1M2EzN2IzOXgxNzg5MDYxODQ4NTQ1MjQ4MDAw parts=121009--- PASS: TestRedundantMultipartUpload (3.76s)1010=== CONT TestCacheStatsHandler10112026-09-10 17:37:30.372 UTC [371] ERROR: relation "goose_db_version" does not exist at character 3610122026-09-10 17:37:30.372 UTC [371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1013=== NAME TestNARDeduplicationMetadataUploadBug1014 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-99968-1879214675/TestNARDeduplicationMetadataUploadBug2451315486/001/store/1kkdjwpr2bv4fdx0kn5syiy1qhsb11vq-file1.txt10152026/09/10 17:37:30 WARN readiness check failed error="closed pool"1016--- PASS: TestService_readinessHandler (2.84s)1017=== CONT TestClaim_StaleHeartbeatStolen10182026/09/10 17:37:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10192026/09/10 17:37:30 OK 20241026095416_initial_model.sql (146.86ms)10202026/09/10 17:37:30 OK 20251210153512_drop_unused_gin_index.sql (11.88ms)10212026/09/10 17:37:30 OK 20251218171726_add_pins.sql (23.7ms)10222026/09/10 17:37:30 INFO Received uploads request method=POST path=/api/pending_closures10232026/09/10 17:37:30 OK 20260628120000_add_object_size_and_stats.sql (21.2ms)10242026/09/10 17:37:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10252026/09/10 17:37:30 INFO Uploading 1kkdjwpr2bv4fdx0kn5syiy1qhsb11vq-file1.txt (160B)10262026/09/10 17:37:30 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10272026/09/10 17:37:30 OK 20260905000000_add_claims.sql (28.26ms)10282026/09/10 17:37:30 goose: successfully migrated database to version: 2026090500000010292026-09-10 17:37:30.668 UTC [381] ERROR: relation "goose_db_version" does not exist at character 3610302026-09-10 17:37:30.668 UTC [381] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10312026/09/10 17:37:30 OK 1_commit_pending_closure.sql (1.55ms)10322026/09/10 17:37:30 OK 2_object_stats_trigger.sql (228.38µs)10332026/09/10 17:37:30 goose: up to current file version: 210342026/09/10 17:37:30 WARN Failed to register uploaded object key=1kkdjwpr2bv4fdx0kn5syiy1qhsb11vq.ls error="server returned 404: 404 page not found\n"10352026/09/10 17:37:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10362026/09/10 17:37:30 INFO Signed narinfos id=1 count=110372026/09/10 17:37:30 INFO Uploading 1 narinfos10382026/09/10 17:37:30 WARN Failed to register uploaded object key=1kkdjwpr2bv4fdx0kn5syiy1qhsb11vq.narinfo error="server returned 404: 404 page not found\n"10392026/09/10 17:37:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10402026/09/10 17:37:30 INFO Completed upload id=110412026/09/10 17:37:30 INFO Upload complete. (210ms)1042=== NAME TestNARDeduplicationMetadataUploadBug1043 metadata_upload_test.go:54: Retrieved narinfo from S3:1044 StorePath: /nix/var/nix/builds/nix-99968-1879214675/TestNARDeduplicationMetadataUploadBug2451315486/001/store/1kkdjwpr2bv4fdx0kn5syiy1qhsb11vq-file1.txt1045 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1046 Compression: zstd1047 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1048 NarSize: 1601049 References: 1050 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1051 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1052 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1053 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1054 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-99968-1879214675/TestNARDeduplicationMetadataUploadBug2451315486/001/store/cwaqj6wpzd705cgnz6zrnh16w2cczjv1-file2.txt10552026/09/10 17:37:30 OK 20241026095416_initial_model.sql (170.6ms)10562026/09/10 17:37:30 OK 20251210153512_drop_unused_gin_index.sql (11.4ms)10572026/09/10 17:37:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10582026/09/10 17:37:30 OK 20251218171726_add_pins.sql (31.39ms)1059--- PASS: TestService_healthCheckHandler (2.48s)1060=== CONT TestClaim_FailWithoutKindReleases10612026/09/10 17:37:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10622026-09-10 17:37:30.963 UTC [389] ERROR: relation "goose_db_version" does not exist at character 3610632026-09-10 17:37:30.963 UTC [389] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10642026/09/10 17:37:30 INFO Received uploads request method=POST path=/api/pending_closures10652026/09/10 17:37:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10662026/09/10 17:37:30 OK 20260628120000_add_object_size_and_stats.sql (14.89ms)10672026/09/10 17:37:31 WARN Failed to register uploaded object key=cwaqj6wpzd705cgnz6zrnh16w2cczjv1.ls error="server returned 404: 404 page not found\n"10682026/09/10 17:37:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10692026/09/10 17:37:31 INFO Signed narinfos id=2 count=110702026/09/10 17:37:31 INFO Uploading 1 narinfos10712026/09/10 17:37:31 WARN Failed to register uploaded object key=cwaqj6wpzd705cgnz6zrnh16w2cczjv1.narinfo error="server returned 404: 404 page not found\n"10722026/09/10 17:37:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10732026/09/10 17:37:31 OK 20260905000000_add_claims.sql (87.81ms)10742026/09/10 17:37:31 goose: successfully migrated database to version: 2026090500000010752026/09/10 17:37:31 INFO Completed upload id=210762026/09/10 17:37:31 INFO Upload complete. (187ms)10772026/09/10 17:37:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjQ5NWVjMmUwLTIyMDktNDdmZi05MDE4LTgxZmFmMWUxZTU1ZHgxNzg5MDYxODQ5Njk4NTcxMDAw parts=1010782026/09/10 17:37:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1079=== NAME TestNARDeduplicationMetadataUploadBug1080 metadata_upload_test.go:76: Retrieved narinfo from S3:1081 StorePath: /nix/var/nix/builds/nix-99968-1879214675/TestNARDeduplicationMetadataUploadBug2451315486/001/store/cwaqj6wpzd705cgnz6zrnh16w2cczjv1-file2.txt1082 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1083 Compression: zstd1084 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1085 NarSize: 1601086 References: 1087 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1088 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1089 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1090 {"version":1,"root":{"type":"regular","size":44}}10912026/09/10 17:37:31 OK 1_commit_pending_closure.sql (1.17ms)10922026/09/10 17:37:31 OK 2_object_stats_trigger.sql (548.92µs)10932026/09/10 17:37:31 goose: up to current file version: 210942026/09/10 17:37:31 INFO Completed upload id=110952026/09/10 17:37:31 INFO Received uploads request method=POST path=/api/pending_closures10962026/09/10 17:37:31 INFO Received uploads request method=POST path=/api/pending_closures10972026/09/10 17:37:31 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10982026/09/10 17:37:31 WARN Found objects in DB but missing from S3, will re-upload count=11099--- PASS: TestService_verifyS3Integrity (4.01s)1100=== CONT TestReadProxyHead1101--- PASS: TestNARDeduplicationMetadataUploadBug (3.53s)1102=== CONT TestReadProxyInvalidPath11032026-09-10 17:37:31.116 UTC [397] ERROR: relation "goose_db_version" does not exist at character 3611042026-09-10 17:37:31.116 UTC [397] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/09/10 17:37:31 OK 20241026095416_initial_model.sql (126.97ms)11062026/09/10 17:37:31 OK 20251210153512_drop_unused_gin_index.sql (15.46ms)11072026/09/10 17:37:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11082026/09/10 17:37:31 OK 20251218171726_add_pins.sql (43.37ms)11092026/09/10 17:37:31 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjVjOTZiMTMyLWU2Y2ItNDIwNi1hMWVkLTExN2E2MTc2ZjBhMHgxNzg5MDYxODQ5OTQ2MTE4MDAw parts=1011102026/09/10 17:37:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11112026/09/10 17:37:31 OK 20260628120000_add_object_size_and_stats.sql (16.58ms)11122026/09/10 17:37:31 INFO Completed upload id=111132026/09/10 17:37:31 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011142026/09/10 17:37:31 INFO Received uploads request method=POST path=/api/pending_closures11152026/09/10 17:37:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures11162026/09/10 17:37:31 INFO Aborted multipart uploads count=011172026/09/10 17:37:31 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=011182026/09/10 17:37:31 INFO Vacuumed table table=pending_closures11192026/09/10 17:37:31 OK 20260905000000_add_claims.sql (42.06ms)11202026/09/10 17:37:31 goose: successfully migrated database to version: 2026090500000011212026/09/10 17:37:31 OK 1_commit_pending_closure.sql (2.37ms)11222026/09/10 17:37:31 OK 2_object_stats_trigger.sql (358.13µs)11232026/09/10 17:37:31 goose: up to current file version: 211242026/09/10 17:37:31 OK 20241026095416_initial_model.sql (132.86ms)11252026/09/10 17:37:31 INFO Vacuumed table table=pending_objects11262026/09/10 17:37:31 OK 20251210153512_drop_unused_gin_index.sql (8.76ms)11272026-09-10 17:37:31.323 UTC [402] ERROR: relation "goose_db_version" does not exist at character 3611282026-09-10 17:37:31.323 UTC [402] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11292026/09/10 17:37:31 INFO Received uploads request method=POST path=/api/pending_closures11302026/09/10 17:37:31 OK 20251218171726_add_pins.sql (8.06ms)11312026/09/10 17:37:31 INFO Vacuumed table table=multipart_uploads11322026/09/10 17:37:31 INFO Vacuumed table table=closures11332026/09/10 17:37:31 OK 20260628120000_add_object_size_and_stats.sql (29.7ms)11342026/09/10 17:37:31 INFO Vacuumed table table=objects11352026/09/10 17:37:31 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001136--- PASS: TestService_createPendingClosureHandler (4.15s)1137=== CONT TestReadProxy40411382026/09/10 17:37:31 OK 20260905000000_add_claims.sql (17.13ms)11392026/09/10 17:37:31 goose: successfully migrated database to version: 2026090500000011402026/09/10 17:37:31 OK 1_commit_pending_closure.sql (2.73ms)11412026/09/10 17:37:31 OK 2_object_stats_trigger.sql (448.25µs)11422026/09/10 17:37:31 goose: up to current file version: 211432026/09/10 17:37:31 OK 20241026095416_initial_model.sql (87.48ms)11442026/09/10 17:37:31 OK 20251210153512_drop_unused_gin_index.sql (15.5ms)11452026/09/10 17:37:31 OK 20251218171726_add_pins.sql (18.94ms)11462026/09/10 17:37:31 OK 20260628120000_add_object_size_and_stats.sql (41.62ms)1147--- PASS: TestReadRedirectKeepsNarinfoProxied (2.43s)1148=== CONT TestReadProxyNarStreaming11492026/09/10 17:37:31 OK 20260905000000_add_claims.sql (88.83ms)11502026/09/10 17:37:31 goose: successfully migrated database to version: 2026090500000011512026/09/10 17:37:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11522026/09/10 17:37:31 OK 1_commit_pending_closure.sql (15.01ms)11532026/09/10 17:37:31 OK 2_object_stats_trigger.sql (483.67µs)11542026/09/10 17:37:31 goose: up to current file version: 21155--- PASS: TestReadProxyRangeRequest (2.59s)1156=== CONT TestReadProxyNarinfoAlreadyDecompressed11572026-09-10 17:37:32.075 UTC [411] ERROR: relation "goose_db_version" does not exist at character 3611582026-09-10 17:37:32.075 UTC [411] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11592026-09-10 17:37:32.190 UTC [412] ERROR: relation "goose_db_version" does not exist at character 3611602026-09-10 17:37:32.190 UTC [412] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/09/10 17:37:32 OK 20241026095416_initial_model.sql (76.54ms)1162--- PASS: TestReadRedirectNar (2.60s)1163=== CONT TestReadProxyNarinfo11642026/09/10 17:37:32 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)11652026/09/10 17:37:32 OK 20251218171726_add_pins.sql (27.56ms)11662026/09/10 17:37:32 OK 20260628120000_add_object_size_and_stats.sql (14.61ms)11672026/09/10 17:37:32 OK 20260905000000_add_claims.sql (26.33ms)11682026/09/10 17:37:32 goose: successfully migrated database to version: 2026090500000011692026/09/10 17:37:32 OK 1_commit_pending_closure.sql (1.98ms)11702026/09/10 17:37:32 OK 2_object_stats_trigger.sql (370.88µs)11712026/09/10 17:37:32 goose: up to current file version: 211722026/09/10 17:37:32 OK 20241026095416_initial_model.sql (123.52ms)11732026/09/10 17:37:32 OK 20251210153512_drop_unused_gin_index.sql (7.86ms)11742026/09/10 17:37:32 OK 20251218171726_add_pins.sql (23.46ms)11752026/09/10 17:37:32 OK 20260628120000_add_object_size_and_stats.sql (47.25ms)11762026/09/10 17:37:32 OK 20260905000000_add_claims.sql (46.71ms)11772026/09/10 17:37:32 goose: successfully migrated database to version: 2026090500000011782026/09/10 17:37:32 OK 1_commit_pending_closure.sql (2.6ms)11792026/09/10 17:37:32 OK 2_object_stats_trigger.sql (482.38µs)11802026/09/10 17:37:32 goose: up to current file version: 21181--- PASS: TestCacheStatsHandler (2.37s)1182=== CONT TestIsValidCachePath1183=== RUN TestIsValidCachePath/narinfo1184=== PAUSE TestIsValidCachePath/narinfo1185=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1186=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1187=== RUN TestIsValidCachePath/nar_zst1188=== PAUSE TestIsValidCachePath/nar_zst1189=== RUN TestIsValidCachePath/nar_xz1190=== PAUSE TestIsValidCachePath/nar_xz1191=== RUN TestIsValidCachePath/nar_bz21192=== PAUSE TestIsValidCachePath/nar_bz21193=== RUN TestIsValidCachePath/nar_uncompressed1194=== PAUSE TestIsValidCachePath/nar_uncompressed1195=== RUN TestIsValidCachePath/ls1196=== PAUSE TestIsValidCachePath/ls1197=== RUN TestIsValidCachePath/log1198=== PAUSE TestIsValidCachePath/log1199=== RUN TestIsValidCachePath/realisation1200=== PAUSE TestIsValidCachePath/realisation1201=== RUN TestIsValidCachePath/nix-cache-info1202=== PAUSE TestIsValidCachePath/nix-cache-info1203=== RUN TestIsValidCachePath/index.html1204=== PAUSE TestIsValidCachePath/index.html1205=== RUN TestIsValidCachePath/traversal_parent1206=== PAUSE TestIsValidCachePath/traversal_parent1207=== RUN TestIsValidCachePath/traversal_in_middle1208=== PAUSE TestIsValidCachePath/traversal_in_middle1209=== RUN TestIsValidCachePath/invalid_char_e1210=== PAUSE TestIsValidCachePath/invalid_char_e1211=== RUN TestIsValidCachePath/invalid_char_u1212=== PAUSE TestIsValidCachePath/invalid_char_u1213=== RUN TestIsValidCachePath/random_path1214=== PAUSE TestIsValidCachePath/random_path1215=== RUN TestIsValidCachePath/empty1216=== PAUSE TestIsValidCachePath/empty1217=== RUN TestIsValidCachePath/leading_slash1218=== PAUSE TestIsValidCachePath/leading_slash1219=== RUN TestIsValidCachePath/wrong_extension1220=== PAUSE TestIsValidCachePath/wrong_extension1221=== RUN TestIsValidCachePath/short_hash1222=== PAUSE TestIsValidCachePath/short_hash1223=== CONT TestParseSingleRange1224=== RUN TestParseSingleRange/none1225=== PAUSE TestParseSingleRange/none1226=== RUN TestParseSingleRange/unknown_unit1227=== PAUSE TestParseSingleRange/unknown_unit1228=== RUN TestParseSingleRange/multi-range_ignored1229=== PAUSE TestParseSingleRange/multi-range_ignored1230=== RUN TestParseSingleRange/malformed_no_dash1231=== PAUSE TestParseSingleRange/malformed_no_dash1232=== RUN TestParseSingleRange/malformed_both_empty1233=== PAUSE TestParseSingleRange/malformed_both_empty1234=== RUN TestParseSingleRange/malformed_end_before_start1235=== PAUSE TestParseSingleRange/malformed_end_before_start1236=== RUN TestParseSingleRange/closed1237=== PAUSE TestParseSingleRange/closed1238=== RUN TestParseSingleRange/open-ended1239=== PAUSE TestParseSingleRange/open-ended1240=== RUN TestParseSingleRange/end_clamped_to_size1241=== PAUSE TestParseSingleRange/end_clamped_to_size1242=== RUN TestParseSingleRange/suffix1243=== PAUSE TestParseSingleRange/suffix1244=== RUN TestParseSingleRange/suffix_exceeds_size1245=== PAUSE TestParseSingleRange/suffix_exceeds_size1246=== RUN TestParseSingleRange/single_byte1247=== PAUSE TestParseSingleRange/single_byte1248=== RUN TestParseSingleRange/start_past_EOF1249=== PAUSE TestParseSingleRange/start_past_EOF1250=== RUN TestParseSingleRange/start_far_past_EOF1251=== PAUSE TestParseSingleRange/start_far_past_EOF1252=== CONT TestResurrectedObjectNotDeleted12532026/09/10 17:37:32 WARN claim: cannot clear write deadline error="feature not supported"12542026-09-10 17:37:32.912 UTC [424] ERROR: relation "goose_db_version" does not exist at character 3612552026-09-10 17:37:32.912 UTC [424] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12562026/09/10 17:37:32 WARN claim: cannot clear write deadline error="feature not supported"1257--- PASS: TestClaim_StaleHeartbeatStolen (2.38s)1258=== CONT TestOrphanedObjectsGCStressTest12592026-09-10 17:37:32.990 UTC [464] ERROR: relation "goose_db_version" does not exist at character 3612602026-09-10 17:37:32.990 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12612026/09/10 17:37:33 OK 20241026095416_initial_model.sql (102.11ms)12622026/09/10 17:37:33 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)12632026/09/10 17:37:33 OK 20251218171726_add_pins.sql (8.14ms)12642026-09-10 17:37:33.102 UTC [467] ERROR: relation "goose_db_version" does not exist at character 3612652026-09-10 17:37:33.102 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12662026/09/10 17:37:33 OK 20260628120000_add_object_size_and_stats.sql (33.26ms)12672026/09/10 17:37:33 OK 20241026095416_initial_model.sql (112.87ms)12682026/09/10 17:37:33 OK 20251210153512_drop_unused_gin_index.sql (8.42ms)12692026/09/10 17:37:33 OK 20260905000000_add_claims.sql (30.71ms)12702026/09/10 17:37:33 goose: successfully migrated database to version: 2026090500000012712026/09/10 17:37:33 OK 1_commit_pending_closure.sql (3.35ms)12722026/09/10 17:37:33 OK 2_object_stats_trigger.sql (619.58µs)12732026/09/10 17:37:33 goose: up to current file version: 212742026/09/10 17:37:33 OK 20251218171726_add_pins.sql (44.06ms)12752026/09/10 17:37:33 OK 20260628120000_add_object_size_and_stats.sql (54.15ms)12762026-09-10 17:37:33.338 UTC [472] ERROR: relation "goose_db_version" does not exist at character 3612772026-09-10 17:37:33.338 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12782026/09/10 17:37:33 OK 20260905000000_add_claims.sql (78.34ms)12792026/09/10 17:37:33 goose: successfully migrated database to version: 2026090500000012802026/09/10 17:37:33 OK 1_commit_pending_closure.sql (6.52ms)12812026/09/10 17:37:33 OK 2_object_stats_trigger.sql (836µs)12822026/09/10 17:37:33 goose: up to current file version: 212832026/09/10 17:37:33 OK 20241026095416_initial_model.sql (232.87ms)12842026/09/10 17:37:33 OK 20251210153512_drop_unused_gin_index.sql (16.36ms)12852026/09/10 17:37:33 OK 20251218171726_add_pins.sql (41.35ms)12862026/09/10 17:37:33 OK 20260628120000_add_object_size_and_stats.sql (40.82ms)12872026/09/10 17:37:33 OK 20260905000000_add_claims.sql (57.3ms)12882026/09/10 17:37:33 goose: successfully migrated database to version: 2026090500000012892026/09/10 17:37:33 WARN claim: cannot clear write deadline error="feature not supported"12902026/09/10 17:37:33 OK 1_commit_pending_closure.sql (13.35ms)12912026/09/10 17:37:33 OK 2_object_stats_trigger.sql (1.24ms)12922026/09/10 17:37:33 goose: up to current file version: 212932026/09/10 17:37:33 WARN claim: cannot clear write deadline error="feature not supported"1294--- PASS: TestClaim_FailWithoutKindReleases (2.61s)1295=== CONT TestOrphanedObjectsGC12962026/09/10 17:37:33 OK 20241026095416_initial_model.sql (229.26ms)12972026/09/10 17:37:33 OK 20251210153512_drop_unused_gin_index.sql (15.16ms)12982026/09/10 17:37:33 OK 20251218171726_add_pins.sql (24.43ms)12992026/09/10 17:37:33 OK 20260628120000_add_object_size_and_stats.sql (18.58ms)13002026-09-10 17:37:33.722 UTC [484] ERROR: relation "goose_db_version" does not exist at character 3613012026-09-10 17:37:33.722 UTC [484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13022026/09/10 17:37:33 OK 20260905000000_add_claims.sql (57.8ms)13032026/09/10 17:37:33 goose: successfully migrated database to version: 2026090500000013042026/09/10 17:37:33 OK 1_commit_pending_closure.sql (6.92ms)13052026/09/10 17:37:33 OK 2_object_stats_trigger.sql (1.06ms)13062026/09/10 17:37:33 goose: up to current file version: 21307--- PASS: TestReadProxyHead (2.87s)1308=== CONT TestObjectStatsTrigger13092026-09-10 17:37:34.017 UTC [488] ERROR: relation "goose_db_version" does not exist at character 3613102026-09-10 17:37:34.017 UTC [488] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13112026/09/10 17:37:34 OK 20241026095416_initial_model.sql (226.64ms)13122026/09/10 17:37:34 OK 20251210153512_drop_unused_gin_index.sql (20.35ms)13132026/09/10 17:37:34 OK 20251218171726_add_pins.sql (22.84ms)13142026/09/10 17:37:34 OK 20260628120000_add_object_size_and_stats.sql (37.59ms)13152026/09/10 17:37:34 OK 20260905000000_add_claims.sql (91.29ms)13162026/09/10 17:37:34 goose: successfully migrated database to version: 2026090500000013172026/09/10 17:37:34 OK 1_commit_pending_closure.sql (11.39ms)13182026/09/10 17:37:34 OK 2_object_stats_trigger.sql (1.08ms)13192026/09/10 17:37:34 goose: up to current file version: 21320--- PASS: TestReadProxyInvalidPath (3.15s)1321=== CONT TestClaim_FailWakesWaitersButIsNotRemembered13222026/09/10 17:37:34 OK 20241026095416_initial_model.sql (283.87ms)13232026/09/10 17:37:34 OK 20251210153512_drop_unused_gin_index.sql (24.73ms)13242026-09-10 17:37:34.418 UTC [493] ERROR: relation "goose_db_version" does not exist at character 3613252026-09-10 17:37:34.418 UTC [493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13262026/09/10 17:37:34 OK 20251218171726_add_pins.sql (23.61ms)13272026/09/10 17:37:34 OK 20260628120000_add_object_size_and_stats.sql (31.12ms)13282026/09/10 17:37:34 OK 20260905000000_add_claims.sql (48.46ms)13292026/09/10 17:37:34 goose: successfully migrated database to version: 2026090500000013302026/09/10 17:37:34 OK 1_commit_pending_closure.sql (6.03ms)13312026/09/10 17:37:34 OK 2_object_stats_trigger.sql (1.01ms)13322026/09/10 17:37:34 goose: up to current file version: 21333--- PASS: TestReadProxy404 (3.27s)1334=== CONT TestClaim_HolderDisconnectKeepsClaim13352026/09/10 17:37:34 OK 20241026095416_initial_model.sql (212.73ms)13362026/09/10 17:37:34 OK 20251210153512_drop_unused_gin_index.sql (17.27ms)13372026/09/10 17:37:34 OK 20251218171726_add_pins.sql (41.43ms)13382026-09-10 17:37:34.771 UTC [497] ERROR: relation "goose_db_version" does not exist at character 3613392026-09-10 17:37:34.771 UTC [497] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13402026/09/10 17:37:34 OK 20260628120000_add_object_size_and_stats.sql (26.52ms)13412026/09/10 17:37:34 OK 20260905000000_add_claims.sql (64.64ms)13422026/09/10 17:37:34 goose: successfully migrated database to version: 2026090500000013432026/09/10 17:37:34 OK 1_commit_pending_closure.sql (4.36ms)13442026/09/10 17:37:34 OK 2_object_stats_trigger.sql (865.5µs)13452026/09/10 17:37:34 goose: up to current file version: 21346--- PASS: TestReadProxyNarStreaming (3.40s)1347=== CONT TestServerTLSConfig/not_a_PEM_file1348=== CONT TestClaim_TwoInstances13492026/09/10 17:37:35 OK 20241026095416_initial_model.sql (176.73ms)13502026/09/10 17:37:35 OK 20251210153512_drop_unused_gin_index.sql (8.19ms)13512026-09-10 17:37:35.045 UTC [502] ERROR: relation "goose_db_version" does not exist at character 3613522026-09-10 17:37:35.045 UTC [502] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13532026/09/10 17:37:35 OK 20251218171726_add_pins.sql (12.74ms)13542026/09/10 17:37:35 OK 20260628120000_add_object_size_and_stats.sql (20.4ms)13552026/09/10 17:37:35 WARN Rate limiter enabled after throttle name=s3-test rate=513562026/09/10 17:37:35 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1357=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1358 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101359 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001360--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.26s)1361=== CONT TestGCTaskStore_ConflictDifferentParams1362--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1363=== CONT TestGCTaskStore_DeduplicateSameParams1364--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1365=== CONT TestGCTaskStore_StartNew1366--- PASS: TestGCTaskStore_StartNew (0.00s)1367=== CONT TestGCMetrics13682026/09/10 17:37:35 OK 20260905000000_add_claims.sql (38.83ms)13692026/09/10 17:37:35 goose: successfully migrated database to version: 2026090500000013702026/09/10 17:37:35 OK 1_commit_pending_closure.sql (3.36ms)13712026/09/10 17:37:35 OK 2_object_stats_trigger.sql (341.21µs)13722026/09/10 17:37:35 goose: up to current file version: 213732026/09/10 17:37:35 OK 20241026095416_initial_model.sql (113.36ms)13742026/09/10 17:37:35 OK 20251210153512_drop_unused_gin_index.sql (1.17ms)1375--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.23s)1376=== CONT TestGCBugBareHashReferences13772026/09/10 17:37:35 OK 20251218171726_add_pins.sql (21.14ms)13782026/09/10 17:37:35 OK 20260628120000_add_object_size_and_stats.sql (28.42ms)13792026-09-10 17:37:35.279 UTC [511] ERROR: relation "goose_db_version" does not exist at character 3613802026-09-10 17:37:35.279 UTC [511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13812026/09/10 17:37:35 OK 20260905000000_add_claims.sql (30.91ms)13822026/09/10 17:37:35 goose: successfully migrated database to version: 2026090500000013832026/09/10 17:37:35 OK 1_commit_pending_closure.sql (1.89ms)13842026/09/10 17:37:35 OK 2_object_stats_trigger.sql (354.92µs)13852026/09/10 17:37:35 goose: up to current file version: 21386--- PASS: TestReadProxyNarinfo (3.20s)1387=== CONT TestResolveDBConnectionString1388=== RUN TestResolveDBConnectionString/flag_wins1389=== PAUSE TestResolveDBConnectionString/flag_wins1390=== RUN TestResolveDBConnectionString/file_when_flag_empty1391=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1392=== RUN TestResolveDBConnectionString/missing_file_is_an_error1393=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1394=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1395=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1396=== RUN TestResolveDBConnectionString/nothing_configured1397=== PAUSE TestResolveDBConnectionString/nothing_configured1398=== CONT TestPinProtectsFromGC13992026/09/10 17:37:35 OK 20241026095416_initial_model.sql (125.31ms)14002026/09/10 17:37:35 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)14012026/09/10 17:37:35 OK 20251218171726_add_pins.sql (18.4ms)14022026/09/10 17:37:35 OK 20260628120000_add_object_size_and_stats.sql (18.53ms)14032026/09/10 17:37:35 OK 20260905000000_add_claims.sql (39.73ms)14042026/09/10 17:37:35 goose: successfully migrated database to version: 2026090500000014052026/09/10 17:37:35 OK 1_commit_pending_closure.sql (4.92ms)14062026/09/10 17:37:35 OK 2_object_stats_trigger.sql (893.17µs)14072026/09/10 17:37:35 goose: up to current file version: 214082026-09-10 17:37:35.616 UTC [514] ERROR: relation "goose_db_version" does not exist at character 3614092026-09-10 17:37:35.616 UTC [514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1410--- PASS: TestResurrectedObjectNotDeleted (3.10s)1411=== CONT TestClientWithDependencies14122026/09/10 17:37:35 OK 20241026095416_initial_model.sql (79.81ms)14132026/09/10 17:37:35 OK 20251210153512_drop_unused_gin_index.sql (5.97ms)14142026/09/10 17:37:35 OK 20251218171726_add_pins.sql (11.64ms)14152026/09/10 17:37:35 OK 20260628120000_add_object_size_and_stats.sql (31.59ms)14162026/09/10 17:37:35 OK 20260905000000_add_claims.sql (37.24ms)14172026/09/10 17:37:35 goose: successfully migrated database to version: 2026090500000014182026/09/10 17:37:35 OK 1_commit_pending_closure.sql (10.14ms)14192026/09/10 17:37:35 OK 2_object_stats_trigger.sql (735.38µs)14202026/09/10 17:37:35 goose: up to current file version: 214212026-09-10 17:37:35.856 UTC [518] ERROR: relation "goose_db_version" does not exist at character 3614222026-09-10 17:37:35.856 UTC [518] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14232026-09-10 17:37:35.982 UTC [521] ERROR: relation "goose_db_version" does not exist at character 3614242026-09-10 17:37:35.982 UTC [521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14252026/09/10 17:37:35 OK 20241026095416_initial_model.sql (108.02ms)14262026/09/10 17:37:35 OK 20251210153512_drop_unused_gin_index.sql (5.2ms)14272026/09/10 17:37:36 OK 20251218171726_add_pins.sql (24.84ms)14282026/09/10 17:37:36 OK 20260628120000_add_object_size_and_stats.sql (39.05ms)14292026/09/10 17:37:36 OK 20260905000000_add_claims.sql (51.22ms)14302026/09/10 17:37:36 goose: successfully migrated database to version: 2026090500000014312026/09/10 17:37:36 OK 1_commit_pending_closure.sql (5.89ms)14322026/09/10 17:37:36 OK 2_object_stats_trigger.sql (1.53ms)14332026/09/10 17:37:36 goose: up to current file version: 214342026/09/10 17:37:36 OK 20241026095416_initial_model.sql (140.91ms)14352026/09/10 17:37:36 OK 20251210153512_drop_unused_gin_index.sql (8.16ms)14362026/09/10 17:37:36 OK 20251218171726_add_pins.sql (27.13ms)14372026/09/10 17:37:36 OK 20260628120000_add_object_size_and_stats.sql (26.62ms)14382026/09/10 17:37:36 OK 20260905000000_add_claims.sql (30.44ms)14392026/09/10 17:37:36 goose: successfully migrated database to version: 2026090500000014402026/09/10 17:37:36 OK 1_commit_pending_closure.sql (4.8ms)14412026/09/10 17:37:36 OK 2_object_stats_trigger.sql (890.21µs)14422026/09/10 17:37:36 goose: up to current file version: 214432026-09-10 17:37:36.275 UTC [524] ERROR: relation "goose_db_version" does not exist at character 3614442026-09-10 17:37:36.275 UTC [524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14452026-09-10 17:37:36.327 UTC [525] ERROR: relation "goose_db_version" does not exist at character 3614462026-09-10 17:37:36.327 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1447--- PASS: TestObjectStatsTrigger (2.49s)1448=== CONT TestClientMultipleUploads14492026-09-10 17:37:36.439 UTC [527] ERROR: relation "goose_db_version" does not exist at character 3614502026-09-10 17:37:36.439 UTC [527] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14512026/09/10 17:37:36 OK 20241026095416_initial_model.sql (113.31ms)14522026/09/10 17:37:36 OK 20251210153512_drop_unused_gin_index.sql (7.38ms)14532026/09/10 17:37:36 OK 20251218171726_add_pins.sql (4.43ms)14542026/09/10 17:37:36 OK 20241026095416_initial_model.sql (73.21ms)14552026/09/10 17:37:36 OK 20251210153512_drop_unused_gin_index.sql (5.95ms)14562026/09/10 17:37:36 OK 20251218171726_add_pins.sql (10.88ms)14572026/09/10 17:37:36 OK 20260628120000_add_object_size_and_stats.sql (25.82ms)14582026/09/10 17:37:36 OK 20260628120000_add_object_size_and_stats.sql (15.9ms)14592026/09/10 17:37:36 OK 20260905000000_add_claims.sql (18.26ms)14602026/09/10 17:37:36 goose: successfully migrated database to version: 2026090500000014612026/09/10 17:37:36 OK 1_commit_pending_closure.sql (2.1ms)14622026/09/10 17:37:36 OK 2_object_stats_trigger.sql (480.21µs)14632026/09/10 17:37:36 goose: up to current file version: 214642026/09/10 17:37:36 OK 20260905000000_add_claims.sql (26.19ms)14652026/09/10 17:37:36 goose: successfully migrated database to version: 2026090500000014662026/09/10 17:37:36 OK 1_commit_pending_closure.sql (2.14ms)14672026/09/10 17:37:36 OK 2_object_stats_trigger.sql (415.29µs)14682026/09/10 17:37:36 goose: up to current file version: 214692026-09-10 17:37:36.524 UTC [530] ERROR: relation "goose_db_version" does not exist at character 3614702026-09-10 17:37:36.524 UTC [530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14712026/09/10 17:37:36 OK 20241026095416_initial_model.sql (76.23ms)14722026/09/10 17:37:36 OK 20251210153512_drop_unused_gin_index.sql (5.88ms)14732026/09/10 17:37:36 OK 20251218171726_add_pins.sql (14.82ms)14742026/09/10 17:37:36 OK 20260628120000_add_object_size_and_stats.sql (35.91ms)14752026/09/10 17:37:36 WARN claim: cannot clear write deadline error="feature not supported"14762026/09/10 17:37:36 OK 20260905000000_add_claims.sql (8.3ms)14772026/09/10 17:37:36 goose: successfully migrated database to version: 2026090500000014782026/09/10 17:37:36 OK 1_commit_pending_closure.sql (3.3ms)14792026/09/10 17:37:36 WARN claim: cannot clear write deadline error="feature not supported"14802026/09/10 17:37:36 OK 2_object_stats_trigger.sql (1.56ms)14812026/09/10 17:37:36 goose: up to current file version: 214822026/09/10 17:37:36 WARN claim: cannot clear write deadline error="feature not supported"1483--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (2.35s)1484=== CONT TestClientIntegration14852026/09/10 17:37:36 OK 20241026095416_initial_model.sql (86.72ms)1486=== NAME TestOrphanedObjectsGC1487 orphaned_objects_gc_test.go:290: GC Test Summary:1488 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1489 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1490 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1491 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1492 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1493--- PASS: TestOrphanedObjectsGC (3.07s)1494=== CONT TestClientErrorHandling1495=== RUN TestClientErrorHandling/InvalidStorePath1496=== PAUSE TestClientErrorHandling/InvalidStorePath1497=== RUN TestClientErrorHandling/InvalidAuthToken1498=== PAUSE TestClientErrorHandling/InvalidAuthToken1499=== RUN TestClientErrorHandling/ServerNotAvailable1500=== PAUSE TestClientErrorHandling/ServerNotAvailable1501=== CONT TestClientCADerivations15022026/09/10 17:37:36 OK 20251210153512_drop_unused_gin_index.sql (10.3ms)15032026/09/10 17:37:36 OK 20251218171726_add_pins.sql (12.35ms)15042026/09/10 17:37:36 OK 20260628120000_add_object_size_and_stats.sql (20.09ms)15052026/09/10 17:37:36 OK 20260905000000_add_claims.sql (18.92ms)15062026/09/10 17:37:36 goose: successfully migrated database to version: 2026090500000015072026/09/10 17:37:36 OK 1_commit_pending_closure.sql (1.94ms)15082026/09/10 17:37:36 OK 2_object_stats_trigger.sql (371.63µs)15092026/09/10 17:37:36 goose: up to current file version: 215102026-09-10 17:37:36.760 UTC [539] ERROR: relation "goose_db_version" does not exist at character 3615112026-09-10 17:37:36.760 UTC [539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15122026/09/10 17:37:36 WARN claim: cannot clear write deadline error="feature not supported"15132026/09/10 17:37:36 WARN claim: cannot clear write deadline error="feature not supported"15142026/09/10 17:37:36 OK 20241026095416_initial_model.sql (44.73ms)15152026/09/10 17:37:36 OK 20251210153512_drop_unused_gin_index.sql (7.99ms)15162026/09/10 17:37:36 OK 20251218171726_add_pins.sql (12.39ms)15172026/09/10 17:37:36 OK 20260628120000_add_object_size_and_stats.sql (20.12ms)15182026/09/10 17:37:36 OK 20260905000000_add_claims.sql (30.81ms)15192026/09/10 17:37:36 goose: successfully migrated database to version: 2026090500000015202026/09/10 17:37:36 OK 1_commit_pending_closure.sql (5.34ms)15212026/09/10 17:37:36 OK 2_object_stats_trigger.sql (785.92µs)15222026/09/10 17:37:36 goose: up to current file version: 215232026/09/10 17:37:37 WARN claim: cannot clear write deadline error="feature not supported"15242026/09/10 17:37:37 WARN claim: cannot clear write deadline error="feature not supported"15252026/09/10 17:37:37 WARN claim: cannot clear write deadline error="feature not supported"15262026/09/10 17:37:37 INFO Received uploads request method=POST path=/api/pending_closures15272026/09/10 17:37:37 INFO Aborted multipart uploads count=015282026/09/10 17:37:37 WARN Force mode enabled - objects will be deleted immediately without grace period15292026/09/10 17:37:37 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=015302026/09/10 17:37:37 INFO Vacuumed table table=pending_closures15312026/09/10 17:37:37 INFO Vacuumed table table=pending_objects15322026/09/10 17:37:37 INFO Vacuumed table table=multipart_uploads15332026/09/10 17:37:37 INFO Vacuumed table table=closures15342026/09/10 17:37:37 INFO Vacuumed table table=objects1535--- PASS: TestGCMetrics (2.20s)1536=== CONT TestClaim_StreamsThroughServer15372026/09/10 17:37:37 WARN claim: cannot clear write deadline error="feature not supported"15382026-09-10 17:37:37.427 UTC [549] ERROR: relation "goose_db_version" does not exist at character 3615392026-09-10 17:37:37.427 UTC [549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15402026/09/10 17:37:37 OK 20241026095416_initial_model.sql (121.81ms)15412026/09/10 17:37:37 OK 20251210153512_drop_unused_gin_index.sql (7.32ms)15422026/09/10 17:37:37 OK 20251218171726_add_pins.sql (45.21ms)15432026/09/10 17:37:37 OK 20260628120000_add_object_size_and_stats.sql (36.87ms)15442026/09/10 17:37:37 OK 20260905000000_add_claims.sql (35.54ms)15452026/09/10 17:37:37 goose: successfully migrated database to version: 2026090500000015462026/09/10 17:37:37 OK 1_commit_pending_closure.sql (5.39ms)15472026/09/10 17:37:37 OK 2_object_stats_trigger.sql (1.44ms)15482026/09/10 17:37:37 goose: up to current file version: 21549--- PASS: TestGCBugBareHashReferences (2.61s)1550=== CONT TestClaim_InputsTouched15512026-09-10 17:37:37.899 UTC [554] ERROR: relation "goose_db_version" does not exist at character 3615522026-09-10 17:37:37.899 UTC [554] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15532026-09-10 17:37:37.907 UTC [553] ERROR: relation "goose_db_version" does not exist at character 3615542026-09-10 17:37:37.907 UTC [553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15552026/09/10 17:37:38 OK 20241026095416_initial_model.sql (142.21ms)15562026/09/10 17:37:38 OK 20241026095416_initial_model.sql (139.12ms)15572026/09/10 17:37:38 OK 20251210153512_drop_unused_gin_index.sql (6.73ms)15582026/09/10 17:37:38 OK 20251210153512_drop_unused_gin_index.sql (904.13µs)1559=== NAME TestPinProtectsFromGC1560 client_integration_test.go:648: Pinned store path: /nix/var/nix/builds/nix-99968-1879214675/TestPinProtectsFromGC872273076/001/store/r58h1hpa5w4f2pg9ypkvkb6yf4y98dw6-pinned-file.txt1561 client_integration_test.go:649: Unpinned store path: /nix/var/nix/builds/nix-99968-1879214675/TestPinProtectsFromGC872273076/001/store/vmjbjyxmlwkx0ngwbml8jz6rkl4v45bb-unpinned-file.txt15622026/09/10 17:37:38 OK 20251218171726_add_pins.sql (2.62ms)15632026/09/10 17:37:38 OK 20251218171726_add_pins.sql (3.55ms)15642026/09/10 17:37:38 OK 20260628120000_add_object_size_and_stats.sql (30.55ms)15652026/09/10 17:37:38 OK 20260628120000_add_object_size_and_stats.sql (35.97ms)15662026/09/10 17:37:38 OK 20260905000000_add_claims.sql (23.44ms)15672026/09/10 17:37:38 goose: successfully migrated database to version: 2026090500000015682026/09/10 17:37:38 OK 20260905000000_add_claims.sql (30.29ms)15692026/09/10 17:37:38 goose: successfully migrated database to version: 2026090500000015702026/09/10 17:37:38 OK 1_commit_pending_closure.sql (5.95ms)15712026/09/10 17:37:38 OK 1_commit_pending_closure.sql (5.94ms)15722026/09/10 17:37:38 OK 2_object_stats_trigger.sql (245.25µs)15732026/09/10 17:37:38 goose: up to current file version: 215742026/09/10 17:37:38 OK 2_object_stats_trigger.sql (285.04µs)15752026/09/10 17:37:38 goose: up to current file version: 215762026/09/10 17:37:38 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15772026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures15782026/09/10 17:37:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15792026/09/10 17:37:38 INFO Uploading r58h1hpa5w4f2pg9ypkvkb6yf4y98dw6-pinned-file.txt (128B)15802026/09/10 17:37:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15812026/09/10 17:37:38 WARN Failed to register uploaded object key=r58h1hpa5w4f2pg9ypkvkb6yf4y98dw6.ls error="server returned 404: 404 page not found\n"15822026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15832026/09/10 17:37:38 INFO Signed narinfos id=1 count=115842026/09/10 17:37:38 INFO Uploading 1 narinfos15852026/09/10 17:37:38 WARN Failed to register uploaded object key=r58h1hpa5w4f2pg9ypkvkb6yf4y98dw6.narinfo error="server returned 404: 404 page not found\n"15862026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15872026/09/10 17:37:38 INFO Completed upload id=115882026/09/10 17:37:38 INFO Upload complete. (223ms)15892026/09/10 17:37:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15902026/09/10 17:37:38 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15912026/09/10 17:37:38 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLmUyNDczMWE2LWY2NGMtNDA5Mi1iM2Y4LTg1ODk1MmY0YTdlOHgxNzg5MDYxODU3MTA0OTUzMDAw parts=1015922026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15932026/09/10 17:37:38 INFO Signed narinfos id=1 count=115942026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15952026/09/10 17:37:38 INFO Completed upload id=11596--- PASS: TestClaim_TwoInstances (3.46s)1597=== CONT TestService_AuthMiddleware_OIDC15982026/09/10 17:37:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50413/oidc1599=== NAME TestClientMultipleUploads1600 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-99968-1879214675/TestClientMultipleUploads2262038246/001/store/p1zrdb2dpqnqrdm46zxlqmdfzfmq0wpj-test-file-0.txt1601=== NAME TestClientWithDependencies1602 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-99968-1879214675/TestClientWithDependencies2156315242/001/store/vs88nzkqb8n24j03i063bbkn1rahxfzv-test-script16032026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures16042026/09/10 17:37:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16052026/09/10 17:37:38 INFO Uploading vmjbjyxmlwkx0ngwbml8jz6rkl4v45bb-unpinned-file.txt (128B)16062026/09/10 17:37:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16072026/09/10 17:37:38 WARN Failed to register uploaded object key=vmjbjyxmlwkx0ngwbml8jz6rkl4v45bb.ls error="server returned 404: 404 page not found\n"16082026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16092026-09-10 17:37:38.509 UTC [582] ERROR: relation "goose_db_version" does not exist at character 3616102026-09-10 17:37:38.509 UTC [582] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16112026/09/10 17:37:38 INFO Signed narinfos id=2 count=116122026/09/10 17:37:38 INFO Uploading 1 narinfos16132026/09/10 17:37:38 WARN Failed to register uploaded object key=vmjbjyxmlwkx0ngwbml8jz6rkl4v45bb.narinfo error="server returned 404: 404 page not found\n"16142026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16152026/09/10 17:37:38 INFO Completed upload id=216162026/09/10 17:37:38 INFO Upload complete. (117ms)1617 client_integration_test.go:596: Found 1 dependencies (including self)1618=== NAME TestClientMultipleUploads1619 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-99968-1879214675/TestClientMultipleUploads2262038246/001/store/pcnjdv6mxrdyjy42biifsvsas4x9zndq-test-file-1.txt16202026/09/10 17:37:38 INFO Received create pin request method=POST path=/api/pins/myapp16212026/09/10 17:37:38 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-99968-1879214675/TestPinProtectsFromGC872273076/001/store/r58h1hpa5w4f2pg9ypkvkb6yf4y98dw6-pinned-file.txt narinfo_key=r58h1hpa5w4f2pg9ypkvkb6yf4y98dw6.narinfo16222026/09/10 17:37:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures16232026/09/10 17:37:38 INFO Garbage collection started1624 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-99968-1879214675/TestClientMultipleUploads2262038246/001/store/pak923bhf4h96hc54w5zpdrm164a59kf-test-file-2.txt16252026/09/10 17:37:38 OK 20241026095416_initial_model.sql (47.08ms)16262026/09/10 17:37:38 INFO Aborted multipart uploads count=016272026/09/10 17:37:38 WARN Force mode enabled - objects will be deleted immediately without grace period16282026/09/10 17:37:38 OK 20251210153512_drop_unused_gin_index.sql (7.43ms)16292026/09/10 17:37:38 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16302026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures16312026/09/10 17:37:38 OK 20251218171726_add_pins.sql (15.48ms)16322026/09/10 17:37:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16332026/09/10 17:37:38 INFO Uploading vs88nzkqb8n24j03i063bbkn1rahxfzv-test-script (136B)16342026/09/10 17:37:38 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16352026/09/10 17:37:38 OK 20260628120000_add_object_size_and_stats.sql (9.24ms)16362026/09/10 17:37:38 WARN Failed to register uploaded object key=log/d4vrngx0xb3vl6dnj0w7dkr8x9pnv7ln-test-script.drv error="server returned 404: 404 page not found\n"16372026/09/10 17:37:38 WARN Failed to register uploaded object key=vs88nzkqb8n24j03i063bbkn1rahxfzv.ls error="server returned 404: 404 page not found\n"16382026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16392026/09/10 17:37:38 INFO Signed narinfos id=1 count=116402026/09/10 17:37:38 INFO Uploading 1 narinfos16412026/09/10 17:37:38 WARN Failed to register uploaded object key=vs88nzkqb8n24j03i063bbkn1rahxfzv.narinfo error="server returned 404: 404 page not found\n"16422026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16432026/09/10 17:37:38 OK 20260905000000_add_claims.sql (25.9ms)16442026/09/10 17:37:38 goose: successfully migrated database to version: 2026090500000016452026/09/10 17:37:38 OK 1_commit_pending_closure.sql (1.46ms)16462026/09/10 17:37:38 OK 2_object_stats_trigger.sql (279.08µs)16472026/09/10 17:37:38 goose: up to current file version: 216482026/09/10 17:37:38 INFO Completed upload id=116492026/09/10 17:37:38 INFO Upload complete. (97ms)1650=== NAME TestClientWithDependencies1651 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-99968-1879214675/TestClientWithDependencies2156315242/001/store) requires matching store prefix16522026/09/10 17:37:38 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1653--- PASS: TestClientWithDependencies (2.97s)1654=== CONT TestCacheConfigHandler1655=== RUN TestCacheConfigHandler/full_config,_no_issuer1656=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1657=== RUN TestCacheConfigHandler/no_cache_url_configured1658=== PAUSE TestCacheConfigHandler/no_cache_url_configured1659=== RUN TestCacheConfigHandler/no_signing_keys1660=== PAUSE TestCacheConfigHandler/no_signing_keys1661=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1662=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1663=== CONT TestService_ReadScope_PublicByDefault16642026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures16652026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures16662026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures16672026/09/10 17:37:38 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16682026/09/10 17:37:38 INFO Uploading pcnjdv6mxrdyjy42biifsvsas4x9zndq-test-file-1.txt (160B)16692026/09/10 17:37:38 INFO Uploading pak923bhf4h96hc54w5zpdrm164a59kf-test-file-2.txt (160B)16702026/09/10 17:37:38 INFO Uploading p1zrdb2dpqnqrdm46zxlqmdfzfmq0wpj-test-file-0.txt (160B)16712026/09/10 17:37:38 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16722026/09/10 17:37:38 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16732026/09/10 17:37:38 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16742026/09/10 17:37:38 WARN Failed to register uploaded object key=p1zrdb2dpqnqrdm46zxlqmdfzfmq0wpj.ls error="server returned 404: 404 page not found\n"16752026/09/10 17:37:38 WARN Failed to register uploaded object key=pak923bhf4h96hc54w5zpdrm164a59kf.ls error="server returned 404: 404 page not found\n"16762026/09/10 17:37:38 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=016772026/09/10 17:37:38 WARN Failed to register uploaded object key=pcnjdv6mxrdyjy42biifsvsas4x9zndq.ls error="server returned 404: 404 page not found\n"16782026/09/10 17:37:38 INFO Vacuumed table table=pending_closures16792026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16802026/09/10 17:37:38 INFO Signed narinfos id=1 count=116812026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16822026/09/10 17:37:38 INFO Signed narinfos id=2 count=116832026/09/10 17:37:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16842026/09/10 17:37:38 INFO Signed narinfos id=3 count=116852026/09/10 17:37:38 INFO Uploading 3 narinfos16862026/09/10 17:37:38 INFO Vacuumed table table=pending_objects16872026/09/10 17:37:38 INFO Vacuumed table table=multipart_uploads16882026/09/10 17:37:38 WARN Failed to register uploaded object key=p1zrdb2dpqnqrdm46zxlqmdfzfmq0wpj.narinfo error="server returned 404: 404 page not found\n"16892026/09/10 17:37:38 WARN Failed to register uploaded object key=pcnjdv6mxrdyjy42biifsvsas4x9zndq.narinfo error="server returned 404: 404 page not found\n"16902026/09/10 17:37:38 WARN Failed to register uploaded object key=pak923bhf4h96hc54w5zpdrm164a59kf.narinfo error="server returned 404: 404 page not found\n"16912026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16922026-09-10 17:37:38.842 UTC [611] ERROR: relation "goose_db_version" does not exist at character 3616932026-09-10 17:37:38.842 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16942026/09/10 17:37:38 INFO Vacuumed table table=closures16952026/09/10 17:37:38 INFO Completed upload id=116962026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16972026/09/10 17:37:38 INFO Vacuumed table table=objects16982026/09/10 17:37:38 INFO Completed upload id=216992026/09/10 17:37:38 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17002026/09/10 17:37:38 INFO Completed upload id=317012026/09/10 17:37:38 INFO Upload complete. (230ms)1702=== NAME TestClientMultipleUploads1703 client_integration_test.go:350: Uploaded 3 paths in 276.909375ms1704=== NAME TestClientIntegration1705 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-99968-1879214675/TestClientIntegration4082544332/002/store/82vp781lwd5pspqpbaig7narnwiqidlg-test-file.txt1706=== NAME TestClientCADerivations1707 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-99968-1879214675/TestClientCADerivations107086533/001/store/1kqrqvxzkz4f155p4yk56kfdqa2icqb9-ca-test1708--- PASS: TestClientMultipleUploads (2.47s)1709=== CONT TestClaim_TooManyStreams17102026/09/10 17:37:38 OK 20241026095416_initial_model.sql (56.12ms)1711=== NAME TestClientCADerivations1712 client_ca_test.go:139: Found 1 dependencies (including self)17132026/09/10 17:37:38 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)17142026/09/10 17:37:38 OK 20251218171726_add_pins.sql (14.82ms)17152026/09/10 17:37:38 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17162026/09/10 17:37:38 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)17172026/09/10 17:37:38 OK 20260905000000_add_claims.sql (2.36ms)17182026/09/10 17:37:38 goose: successfully migrated database to version: 2026090500000017192026/09/10 17:37:38 OK 1_commit_pending_closure.sql (1.49ms)17202026/09/10 17:37:38 OK 2_object_stats_trigger.sql (562.46µs)17212026/09/10 17:37:38 goose: up to current file version: 217222026/09/10 17:37:38 INFO Received uploads request method=POST path=/api/pending_closures17232026/09/10 17:37:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17242026/09/10 17:37:39 INFO Uploading 82vp781lwd5pspqpbaig7narnwiqidlg-test-file.txt (152B)17252026/09/10 17:37:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17262026/09/10 17:37:39 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17272026/09/10 17:37:39 WARN Failed to register uploaded object key=82vp781lwd5pspqpbaig7narnwiqidlg.ls error="server returned 404: 404 page not found\n"17282026/09/10 17:37:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17292026/09/10 17:37:39 INFO Signed narinfos id=1 count=117302026/09/10 17:37:39 INFO Uploading 1 narinfos17312026/09/10 17:37:39 WARN Failed to register uploaded object key=82vp781lwd5pspqpbaig7narnwiqidlg.narinfo error="server returned 404: 404 page not found\n"17322026/09/10 17:37:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17332026/09/10 17:37:39 INFO Received uploads request method=POST path=/api/pending_closures17342026/09/10 17:37:39 INFO Completed upload id=117352026/09/10 17:37:39 INFO Upload complete. (134ms)1736=== NAME TestClientIntegration1737 client_integration_test.go:293: Retrieved narinfo from S3:1738 StorePath: /nix/var/nix/builds/nix-99968-1879214675/TestClientIntegration4082544332/002/store/82vp781lwd5pspqpbaig7narnwiqidlg-test-file.txt1739 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1740 Compression: zstd1741 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11742 NarSize: 1521743 References: 1744 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11745 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1746 client_integration_test.go:294: Decompressed .ls content (64 bytes):1747 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1748 client_integration_test.go:297: Testing garbage collection...17492026/09/10 17:37:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17502026/09/10 17:37:39 INFO Uploading 1kqrqvxzkz4f155p4yk56kfdqa2icqb9-ca-test (144B)17512026/09/10 17:37:39 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17522026/09/10 17:37:39 WARN Failed to register uploaded object key=log/45y3afjzqivf3asbssdbw893zbg1nznj-ca-test.drv error="server returned 404: 404 page not found\n"17532026/09/10 17:37:39 WARN Failed to register uploaded object key=1kqrqvxzkz4f155p4yk56kfdqa2icqb9.ls error="server returned 404: 404 page not found\n"17542026/09/10 17:37:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17552026/09/10 17:37:39 INFO Signed narinfos id=1 count=117562026/09/10 17:37:39 INFO Uploading 1 narinfos17572026/09/10 17:37:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures17582026/09/10 17:37:39 INFO Garbage collection started17592026/09/10 17:37:39 INFO Aborted multipart uploads count=017602026/09/10 17:37:39 WARN Failed to register uploaded object key=1kqrqvxzkz4f155p4yk56kfdqa2icqb9.narinfo error="server returned 404: 404 page not found\n"17612026/09/10 17:37:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17622026/09/10 17:37:39 WARN Force mode enabled - objects will be deleted immediately without grace period17632026/09/10 17:37:39 INFO Completed upload id=117642026/09/10 17:37:39 INFO Upload complete. (144ms)1765=== NAME TestClientCADerivations1766 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-99968-1879214675/TestClientCADerivations107086533/001/store/1kqrqvxzkz4f155p4yk56kfdqa2icqb9-ca-test1767 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1768 Compression: zstd1769 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1770 NarSize: 1441771 References: 1772 Deriver: /nix/var/nix/builds/nix-99968-1879214675/TestClientCADerivations107086533/001/store/45y3afjzqivf3asbssdbw893zbg1nznj-ca-test.drv1773 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1774 client_ca_test.go:185: Checking for realisation files in S3...1775 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1776 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17772026/09/10 17:37:39 INFO Received uploads request method=POST path=/api/pending_closures17782026-09-10 17:37:39.143 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3617792026-09-10 17:37:39.143 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17802026-09-10 17:37:39.160 UTC [636] ERROR: relation "goose_db_version" does not exist at character 3617812026-09-10 17:37:39.160 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1782 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket48?endpoint=http://localhost:50243®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-99968-1879214675/TestClientCADerivations107086533/001/store'1783 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11784--- PASS: TestClientCADerivations (2.53s)1785=== CONT TestClaim_GCMarkedOutputCountsAsAbsent17862026/09/10 17:37:39 OK 20241026095416_initial_model.sql (40ms)17872026/09/10 17:37:39 OK 20251210153512_drop_unused_gin_index.sql (7.18ms)17882026/09/10 17:37:39 OK 20251218171726_add_pins.sql (5.89ms)17892026/09/10 17:37:39 OK 20260628120000_add_object_size_and_stats.sql (7.33ms)17902026/09/10 17:37:39 OK 20260905000000_add_claims.sql (8.29ms)17912026/09/10 17:37:39 goose: successfully migrated database to version: 2026090500000017922026/09/10 17:37:39 OK 20241026095416_initial_model.sql (30.2ms)17932026/09/10 17:37:39 OK 1_commit_pending_closure.sql (2.01ms)17942026/09/10 17:37:39 OK 20251210153512_drop_unused_gin_index.sql (761.25µs)17952026/09/10 17:37:39 OK 2_object_stats_trigger.sql (618.46µs)17962026/09/10 17:37:39 goose: up to current file version: 217972026/09/10 17:37:39 OK 20251218171726_add_pins.sql (2.59ms)17982026/09/10 17:37:39 OK 20260628120000_add_object_size_and_stats.sql (8.98ms)17992026/09/10 17:37:39 OK 20260905000000_add_claims.sql (33.68ms)18002026/09/10 17:37:39 goose: successfully migrated database to version: 2026090500000018012026/09/10 17:37:39 OK 1_commit_pending_closure.sql (1.29ms)18022026/09/10 17:37:39 OK 2_object_stats_trigger.sql (250.88µs)18032026/09/10 17:37:39 goose: up to current file version: 218042026/09/10 17:37:39 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=018052026/09/10 17:37:39 INFO Vacuumed table table=pending_closures1806--- PASS: TestClaim_HolderDisconnectKeepsClaim (4.70s)1807=== CONT TestService_RequireScope_OIDC18082026/09/10 17:37:39 INFO Vacuumed table table=pending_objects18092026/09/10 17:37:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50449/oidc18102026/09/10 17:37:39 INFO Vacuumed table table=multipart_uploads18112026/09/10 17:37:39 INFO Vacuumed table table=closures18122026/09/10 17:37:39 INFO Vacuumed table table=objects1813=== NAME TestOrphanedObjectsGCStressTest1814 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1815 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1816=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1817=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1818=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1819=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1820=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1821=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1822=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1823=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1824=== CONT TestClaim_BuildWaitComplete1825--- PASS: TestService_ReadScope_PublicByDefault (1.02s)1826=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18272026-09-10 17:37:39.716 UTC [646] ERROR: relation "goose_db_version" does not exist at character 3618282026-09-10 17:37:39.716 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18292026/09/10 17:37:39 OK 20241026095416_initial_model.sql (58.82ms)18302026/09/10 17:37:39 OK 20251210153512_drop_unused_gin_index.sql (7.42ms)18312026/09/10 17:37:39 OK 20251218171726_add_pins.sql (2.94ms)18322026/09/10 17:37:39 OK 20260628120000_add_object_size_and_stats.sql (3.07ms)18332026/09/10 17:37:39 OK 20260905000000_add_claims.sql (3.71ms)18342026/09/10 17:37:39 goose: successfully migrated database to version: 2026090500000018352026/09/10 17:37:39 OK 1_commit_pending_closure.sql (2.69ms)18362026/09/10 17:37:39 OK 2_object_stats_trigger.sql (742.42µs)18372026/09/10 17:37:39 goose: up to current file version: 218382026/09/10 17:37:40 WARN claim: cannot clear write deadline error="feature not supported"1839--- PASS: TestClaim_TooManyStreams (1.15s)1840=== CONT TestService_ReadAuthMiddleware18412026/09/10 17:37:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18422026/09/10 17:37:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjYzMjY1OTI5LTlkY2EtNGFhOS05YjI0LWJjMDQ2ZjNiMTBkZngxNzg5MDYxODU5MTM0Mjk0MDAw parts=1018432026/09/10 17:37:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18442026/09/10 17:37:40 INFO Completed upload id=118452026/09/10 17:37:40 WARN claim: cannot clear write deadline error="feature not supported"18462026-09-10 17:37:40.148 UTC [651] ERROR: relation "goose_db_version" does not exist at character 3618472026-09-10 17:37:40.148 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18482026/09/10 17:37:40 INFO Aborted multipart uploads count=018492026/09/10 17:37:40 WARN Force mode enabled - objects will be deleted immediately without grace period18502026/09/10 17:37:40 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=018512026/09/10 17:37:40 INFO Vacuumed table table=pending_closures18522026/09/10 17:37:40 INFO Vacuumed table table=pending_objects18532026/09/10 17:37:40 OK 20241026095416_initial_model.sql (10.59ms)18542026/09/10 17:37:40 OK 20251210153512_drop_unused_gin_index.sql (703.25µs)18552026/09/10 17:37:40 OK 20251218171726_add_pins.sql (1.32ms)18562026-09-10 17:37:40.168 UTC [653] ERROR: relation "goose_db_version" does not exist at character 3618572026-09-10 17:37:40.168 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18582026/09/10 17:37:40 INFO Vacuumed table table=multipart_uploads18592026/09/10 17:37:40 INFO Vacuumed table table=closures18602026/09/10 17:37:40 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)18612026/09/10 17:37:40 INFO Vacuumed table table=objects1862--- PASS: TestClaim_InputsTouched (2.36s)1863=== CONT TestServerTLSConfig/missing_CA_file1864--- PASS: TestServerTLSConfig (0.00s)1865 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1866 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1867 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1868=== CONT TestService_AuthMiddleware_MTLSProxyHeader18692026/09/10 17:37:40 OK 20260905000000_add_claims.sql (4.02ms)18702026/09/10 17:37:40 goose: successfully migrated database to version: 2026090500000018712026/09/10 17:37:40 OK 1_commit_pending_closure.sql (2.4ms)18722026/09/10 17:37:40 OK 2_object_stats_trigger.sql (722.54µs)18732026/09/10 17:37:40 goose: up to current file version: 218742026/09/10 17:37:40 OK 20241026095416_initial_model.sql (31.15ms)18752026/09/10 17:37:40 OK 20251210153512_drop_unused_gin_index.sql (7.23ms)18762026/09/10 17:37:40 OK 20251218171726_add_pins.sql (10.25ms)18772026/09/10 17:37:40 OK 20260628120000_add_object_size_and_stats.sql (27.25ms)18782026/09/10 17:37:40 OK 20260905000000_add_claims.sql (23.53ms)18792026/09/10 17:37:40 goose: successfully migrated database to version: 2026090500000018802026/09/10 17:37:40 OK 1_commit_pending_closure.sql (1.83ms)18812026/09/10 17:37:40 OK 2_object_stats_trigger.sql (372.79µs)18822026/09/10 17:37:40 goose: up to current file version: 218832026-09-10 17:37:40.395 UTC [656] ERROR: relation "goose_db_version" does not exist at character 3618842026-09-10 17:37:40.395 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18852026/09/10 17:37:40 INFO Received uploads request method=POST path=/api/pending_closures1886--- PASS: TestClaim_StreamsThroughServer (3.17s)1887=== CONT TestIsValidUploadKey/narinfo1888=== CONT TestIsValidUploadKey/realisation_plus_in_output1889=== CONT TestIsValidUploadKey/nix-cache-info1890=== CONT TestIsValidUploadKey/realisation1891=== CONT TestIsValidUploadKey/build_log_equals1892=== CONT TestIsValidUploadKey/build_log_question_mark1893=== CONT TestIsValidUploadKey/build_log_plus_in_name1894=== CONT TestIsValidUploadKey/build_log_home-manager_file1895=== CONT TestIsValidUploadKey/build_log1896=== CONT TestIsValidUploadKey/listing1897=== CONT TestIsValidUploadKey/nar_plain1898=== CONT TestIsValidUploadKey/nar_xz1899=== CONT TestIsValidUploadKey/nar_zst1900=== CONT TestIsValidUploadKey/traversal1901=== CONT TestIsValidUploadKey/unknown_type1902=== CONT TestIsValidUploadKey/empty_key1903=== CONT TestIsValidUploadKey/absolute1904=== CONT TestIsValidUploadKey/traversal_nar1905=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1906=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1907=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1908=== CONT TestIsValidUploadKey/index.html1909--- PASS: TestIsValidUploadKey (0.00s)1910 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1911 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1912 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1913 --- PASS: TestIsValidUploadKey/realisation (0.00s)1914 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1915 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1916 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1917 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1918 --- PASS: TestIsValidUploadKey/build_log (0.00s)1919 --- PASS: TestIsValidUploadKey/listing (0.00s)1920 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1921 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1922 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1923 --- PASS: TestIsValidUploadKey/traversal (0.00s)1924 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1925 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1926 --- PASS: TestIsValidUploadKey/absolute (0.00s)1927 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1928 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1929 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1930 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1931 --- PASS: TestIsValidUploadKey/index.html (0.00s)1932=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19332026/09/10 17:37:40 INFO Received uploads request method=POST path=/19342026/09/10 17:37:40 OK 20241026095416_initial_model.sql (115.06ms)19352026/09/10 17:37:40 OK 20251210153512_drop_unused_gin_index.sql (11.29ms)19362026/09/10 17:37:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=019372026/09/10 17:37:40 OK 20251218171726_add_pins.sql (14.57ms)1938=== NAME TestPinProtectsFromGC1939 client_integration_test.go:711: Pin successfully protected closure from garbage collection19402026/09/10 17:37:40 OK 20260628120000_add_object_size_and_stats.sql (10.97ms)1941--- PASS: TestPinProtectsFromGC (5.21s)1942=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19432026/09/10 17:37:40 INFO Received request for more parts method=POST path=/1944=== RUN TestService_RequireScope_OIDC/builder_may_write1945=== PAUSE TestService_RequireScope_OIDC/builder_may_write1946=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1947=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1948=== RUN TestService_RequireScope_OIDC/ops_may_admin1949=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1950=== RUN TestService_RequireScope_OIDC/ops_may_not_write1951=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1952=== RUN TestService_RequireScope_OIDC/reader_may_not_write1953=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1954=== RUN TestService_RequireScope_OIDC/static_token_may_admin1955=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1956=== RUN TestService_RequireScope_OIDC/static_token_may_write1957=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1958=== RUN TestService_RequireScope_OIDC/reader_may_read1959=== PAUSE TestService_RequireScope_OIDC/reader_may_read1960=== RUN TestService_RequireScope_OIDC/writer_implies_read1961=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1962=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1963=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1964=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19652026/09/10 17:37:40 INFO Received complete multipart upload request method=POST path=/19662026/09/10 17:37:40 OK 20260905000000_add_claims.sql (42.74ms)19672026/09/10 17:37:40 goose: successfully migrated database to version: 202609050000001968=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19692026/09/10 17:37:40 INFO Received uploads request method=POST path=/1970=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19712026/09/10 17:37:40 INFO Received complete multipart upload request method=POST path=/1972=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19732026/09/10 17:37:40 INFO Received request for more parts method=POST path=/1974=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19752026/09/10 17:37:40 INFO Received uploads request method=POST path=/1976--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1977 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1978 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1979 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1980 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1981=== CONT TestProxyWriteTimeout/narinfo1982=== CONT TestProxyWriteTimeout/10_GiB_nar1983=== CONT TestProxyWriteTimeout/unknown_size1984=== CONT TestProxyWriteTimeout/1_GiB_nar1985--- PASS: TestProxyWriteTimeout (0.00s)1986 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1987 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1988 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1989 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1990=== CONT TestIsValidCachePath/narinfo1991=== CONT TestIsValidCachePath/index.html1992=== CONT TestIsValidCachePath/short_hash1993=== CONT TestIsValidCachePath/wrong_extension1994=== CONT TestIsValidCachePath/leading_slash1995=== CONT TestIsValidCachePath/empty1996=== CONT TestIsValidCachePath/random_path1997=== CONT TestIsValidCachePath/invalid_char_u1998=== CONT TestIsValidCachePath/invalid_char_e1999=== CONT TestIsValidCachePath/traversal_in_middle2000=== CONT TestIsValidCachePath/traversal_parent2001=== CONT TestIsValidCachePath/nar_uncompressed2002=== CONT TestIsValidCachePath/nix-cache-info2003=== CONT TestIsValidCachePath/realisation2004=== CONT TestIsValidCachePath/log2005=== CONT TestIsValidCachePath/ls2006=== CONT TestIsValidCachePath/nar_xz2007=== CONT TestIsValidCachePath/nar_bz22008=== CONT TestIsValidCachePath/nar_zst2009=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2010--- PASS: TestIsValidCachePath (0.00s)2011 --- PASS: TestIsValidCachePath/narinfo (0.00s)2012 --- PASS: TestIsValidCachePath/index.html (0.00s)2013 --- PASS: TestIsValidCachePath/short_hash (0.00s)2014 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2015 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2016 --- PASS: TestIsValidCachePath/empty (0.00s)2017 --- PASS: TestIsValidCachePath/random_path (0.00s)2018 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2019 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2020 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2021 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2022 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2023 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2024 --- PASS: TestIsValidCachePath/realisation (0.00s)2025 --- PASS: TestIsValidCachePath/log (0.00s)2026 --- PASS: TestIsValidCachePath/ls (0.00s)2027 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2028 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2029 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2030 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2031=== CONT TestParseSingleRange/none2032=== CONT TestParseSingleRange/open-ended2033=== CONT TestParseSingleRange/start_far_past_EOF2034=== CONT TestParseSingleRange/start_past_EOF2035=== CONT TestParseSingleRange/single_byte2036=== CONT TestParseSingleRange/suffix_exceeds_size2037=== CONT TestParseSingleRange/suffix2038=== CONT TestParseSingleRange/end_clamped_to_size2039=== CONT TestParseSingleRange/malformed_both_empty2040=== CONT TestParseSingleRange/closed2041=== CONT TestParseSingleRange/malformed_end_before_start2042=== CONT TestParseSingleRange/multi-range_ignored2043=== CONT TestParseSingleRange/malformed_no_dash2044=== CONT TestParseSingleRange/unknown_unit2045--- PASS: TestParseSingleRange (0.00s)2046 --- PASS: TestParseSingleRange/none (0.00s)2047 --- PASS: TestParseSingleRange/open-ended (0.00s)2048 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2049 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2050 --- PASS: TestParseSingleRange/single_byte (0.00s)2051 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2052 --- PASS: TestParseSingleRange/suffix (0.00s)2053 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2054 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2055 --- PASS: TestParseSingleRange/closed (0.00s)2056 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2057 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2058 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2059 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2060=== CONT TestResolveDBConnectionString/flag_wins2061=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2062=== CONT TestResolveDBConnectionString/nothing_configured2063=== CONT TestResolveDBConnectionString/missing_file_is_an_error2064=== CONT TestResolveDBConnectionString/file_when_flag_empty2065=== CONT TestClientErrorHandling/InvalidStorePath20662026/09/10 17:37:40 OK 1_commit_pending_closure.sql (2.92ms)20672026/09/10 17:37:40 OK 2_object_stats_trigger.sql (631.88µs)20682026/09/10 17:37:40 goose: up to current file version: 22069--- PASS: TestResolveDBConnectionString (0.02s)2070 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2071 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2072 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2073 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2074 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2075=== CONT TestClientErrorHandling/ServerNotAvailable20762026-09-10 17:37:40.680 UTC [658] ERROR: relation "goose_db_version" does not exist at character 3620772026-09-10 17:37:40.680 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2078--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2079 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2080 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2081 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.32s)2082=== CONT TestClientErrorHandling/InvalidAuthToken20832026/09/10 17:37:40 OK 20241026095416_initial_model.sql (130.52ms)20842026/09/10 17:37:40 OK 20251210153512_drop_unused_gin_index.sql (7.07ms)20852026/09/10 17:37:40 OK 20251218171726_add_pins.sql (32.93ms)20862026/09/10 17:37:40 WARN claim: cannot clear write deadline error="feature not supported"20872026/09/10 17:37:40 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-config20882026/09/10 17:37:40 OK 20260628120000_add_object_size_and_stats.sql (21.02ms)20892026/09/10 17:37:40 WARN claim: cannot clear write deadline error="feature not supported"20902026/09/10 17:37:40 WARN claim: cannot clear write deadline error="feature not supported"20912026/09/10 17:37:40 INFO Received uploads request method=POST path=/api/pending_closures20922026/09/10 17:37:40 OK 20260905000000_add_claims.sql (10.05ms)20932026/09/10 17:37:40 goose: successfully migrated database to version: 2026090500000020942026/09/10 17:37:40 OK 1_commit_pending_closure.sql (5.41ms)20952026/09/10 17:37:40 OK 2_object_stats_trigger.sql (2.34ms)20962026/09/10 17:37:40 goose: up to current file version: 220972026-09-10 17:37:40.988 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3620982026-09-10 17:37:40.988 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20992026/09/10 17:37:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.176003ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2100=== NAME TestOrphanedObjectsGCStressTest2101 orphaned_objects_gc_test.go:509: Stress test completed successfully:2102 orphaned_objects_gc_test.go:510: - Active objects preserved: 202103 orphaned_objects_gc_test.go:511: - Objects deleted: 2102104 orphaned_objects_gc_test.go:512: - Total GC'd: 2102105--- PASS: TestOrphanedObjectsGCStressTest (8.12s)2106=== CONT TestCacheConfigHandler/full_config,_no_issuer2107=== CONT TestCacheConfigHandler/no_signing_keys2108=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2109=== CONT TestCacheConfigHandler/no_cache_url_configured2110--- PASS: TestCacheConfigHandler (0.00s)2111 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2112 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2113 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2114 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2115=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token21162026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[write]2117=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21182026/09/10 17:37:41 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]2119=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2120=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21212026/09/10 17:37:41 WARN Authentication failed token_preview=eyJhbGciOi...3LQ_b8jRog token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2122=== CONT TestService_RequireScope_OIDC/builder_may_write21232026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[write]2124=== CONT TestService_RequireScope_OIDC/static_token_may_admin2125=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2126=== CONT TestService_RequireScope_OIDC/writer_implies_read21272026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[write]2128=== CONT TestService_RequireScope_OIDC/reader_may_read21292026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[read]2130=== CONT TestService_RequireScope_OIDC/static_token_may_write2131=== CONT TestService_RequireScope_OIDC/ops_may_not_write21322026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[admin]2133=== CONT TestService_RequireScope_OIDC/reader_may_not_write21342026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[read]2135=== CONT TestService_RequireScope_OIDC/ops_may_admin21362026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[admin]2137=== CONT TestService_RequireScope_OIDC/builder_may_not_admin21382026/09/10 17:37:41 INFO OIDC auth successful provider=test scopes=[write]2139--- PASS: TestService_AuthMiddleware_OIDC (0.98s)2140 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2141 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2142 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2143 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2144--- PASS: TestService_RequireScope_OIDC (1.31s)2145 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2146 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2147 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2148 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2149 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2150 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2151 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2152 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2153 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2154 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21552026/09/10 17:37:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02156=== NAME TestClientIntegration2157 client_integration_test.go:304: Objects in database after GC:2158 client_integration_test.go:304: Successfully deleted all objects with GC --force2159--- PASS: TestClientIntegration (4.53s)21602026/09/10 17:37:41 OK 20241026095416_initial_model.sql (138.9ms)21612026/09/10 17:37:41 OK 20251210153512_drop_unused_gin_index.sql (15.88ms)21622026/09/10 17:37:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.328029ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21632026/09/10 17:37:41 OK 20251218171726_add_pins.sql (38.53ms)21642026/09/10 17:37:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21652026/09/10 17:37:41 WARN mTLS auth: bound subjects configured but subject DN unavailable21662026/09/10 17:37:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2167--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.53s)21682026/09/10 17:37:41 OK 20260628120000_add_object_size_and_stats.sql (32.47ms)21692026/09/10 17:37:41 OK 20260905000000_add_claims.sql (4.03ms)21702026/09/10 17:37:41 goose: successfully migrated database to version: 2026090500000021712026/09/10 17:37:41 OK 1_commit_pending_closure.sql (2.25ms)21722026/09/10 17:37:41 OK 2_object_stats_trigger.sql (611.58µs)21732026/09/10 17:37:41 goose: up to current file version: 221742026-09-10 17:37:41.307 UTC [671] ERROR: relation "goose_db_version" does not exist at character 3621752026-09-10 17:37:41.307 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21762026/09/10 17:37:41 OK 20241026095416_initial_model.sql (169.15ms)21772026/09/10 17:37:41 OK 20251210153512_drop_unused_gin_index.sql (10.49ms)2178--- PASS: TestService_ReadAuthMiddleware (1.51s)21792026/09/10 17:37:41 OK 20251218171726_add_pins.sql (25ms)21802026/09/10 17:37:41 OK 20260628120000_add_object_size_and_stats.sql (19.79ms)21812026/09/10 17:37:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21822026/09/10 17:37:41 OK 20260905000000_add_claims.sql (10.54ms)21832026/09/10 17:37:41 goose: successfully migrated database to version: 2026090500000021842026/09/10 17:37:41 OK 1_commit_pending_closure.sql (3.03ms)21852026/09/10 17:37:41 OK 2_object_stats_trigger.sql (725.75µs)21862026/09/10 17:37:41 goose: up to current file version: 221872026/09/10 17:37:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=748.610929ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21882026/09/10 17:37:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLmVmNGRmMjIzLWI4NjktNDIzYi1iODRjLTlkNTcwODY3YWRkZngxNzg5MDYxODYwNDQ1NzIzMDAw parts=1021892026/09/10 17:37:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21902026/09/10 17:37:41 INFO Completed upload id=121912026/09/10 17:37:41 WARN claim: cannot clear write deadline error="feature not supported"21922026/09/10 17:37:41 WARN claim: cannot clear write deadline error="feature not supported"2193--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (2.51s)2194--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.69s)21952026-09-10 17:37:41.940 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3621962026-09-10 17:37:41.940 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21972026-09-10 17:37:41.958 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3621982026-09-10 17:37:41.958 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21992026/09/10 17:37:42 OK 20241026095416_initial_model.sql (70.78ms)22002026/09/10 17:37:42 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)22012026/09/10 17:37:42 OK 20251218171726_add_pins.sql (3.15ms)22022026/09/10 17:37:42 OK 20241026095416_initial_model.sql (37.06ms)22032026/09/10 17:37:42 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)22042026/09/10 17:37:42 OK 20260628120000_add_object_size_and_stats.sql (3.58ms)22052026/09/10 17:37:42 OK 20251218171726_add_pins.sql (2.98ms)22062026/09/10 17:37:42 OK 20260905000000_add_claims.sql (3.2ms)22072026/09/10 17:37:42 goose: successfully migrated database to version: 2026090500000022082026/09/10 17:37:42 OK 20260628120000_add_object_size_and_stats.sql (2.51ms)22092026/09/10 17:37:42 OK 1_commit_pending_closure.sql (2.42ms)22102026/09/10 17:37:42 OK 2_object_stats_trigger.sql (661.96µs)22112026/09/10 17:37:42 goose: up to current file version: 222122026/09/10 17:37:42 OK 20260905000000_add_claims.sql (3.06ms)22132026/09/10 17:37:42 goose: successfully migrated database to version: 2026090500000022142026/09/10 17:37:42 OK 1_commit_pending_closure.sql (1.93ms)22152026/09/10 17:37:42 OK 2_object_stats_trigger.sql (411.08µs)22162026/09/10 17:37:42 goose: up to current file version: 222172026/09/10 17:37:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22182026/09/10 17:37:42 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=MmFhYTU0MzQtMzBhMC00OGQ5LWE0NzctYTRhMDkzNWUyNDQzLjg1ODhhNmNlLTgxOGUtNDhkMy1hYjQ2LWYyMTcyNDk4YzkyZXgxNzg5MDYxODYwOTY5NTYyMDAw parts=1022192026/09/10 17:37:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22202026/09/10 17:37:42 INFO Signed narinfos id=1 count=122212026/09/10 17:37:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22222026/09/10 17:37:42 INFO Received uploads request method=POST path=/api/pending_closures22232026/09/10 17:37:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22242026/09/10 17:37:42 INFO Signed narinfos id=2 count=122252026/09/10 17:37:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22262026/09/10 17:37:42 INFO Completed upload id=222272026/09/10 17:37:42 WARN claim: cannot clear write deadline error="feature not supported"2228--- PASS: TestClaim_BuildWaitComplete (2.72s)22292026/09/10 17:37:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.750410688s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/09/10 17:37:42 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22312026/09/10 17:37:42 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22322026/09/10 17:37:44 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"22332026/09/10 17:37:44 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_closures22342026/09/10 17:37:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.728506ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22352026/09/10 17:37:44 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=415.550771ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22362026/09/10 17:37:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.497171ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22372026/09/10 17:37:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.72585678s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2238--- PASS: TestClientErrorHandling (0.00s)2239 --- PASS: TestClientErrorHandling/InvalidStorePath (1.66s)2240 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.78s)2241 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.91s)2242PASS2243{"timestamp":"2026-09-10T17:37:47.563986Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50328","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1866,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}22442026-09-10 17:37:47.675 UTC [122] LOG: received smart shutdown request22452026-09-10 17:37:47.676 UTC [122] LOG: background worker "logical replication launcher" (PID 132) exited with exit code 122462026-09-10 17:37:47.679 UTC [127] LOG: shutting down22472026-09-10 17:37:47.679 UTC [127] LOG: checkpoint starting: shutdown immediate22482026-09-10 17:37:48.797 UTC [127] LOG: checkpoint complete: wrote 13277 buffers (81.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.752 s, sync=0.364 s, total=1.119 s; sync files=21000, longest=0.001 s, average=0.001 s; distance=287764 kB, estimate=287764 kB; lsn=0/130920C0, redo lsn=0/130920C022492026-09-10 17:37:48.802 UTC [122] LOG: database system is shut down2250Running OIDC tests...2251=== RUN TestGlobMatch2252=== PAUSE TestGlobMatch2253=== RUN TestAudienceForIssuer2254=== PAUSE TestAudienceForIssuer2255=== RUN TestValidateToken_ValidToken2256=== PAUSE TestValidateToken_ValidToken2257=== RUN TestValidateToken_WrongAudience2258=== PAUSE TestValidateToken_WrongAudience2259=== RUN TestValidateToken_Expired2260=== PAUSE TestValidateToken_Expired2261=== RUN TestValidateToken_BoundClaimsMismatch2262=== PAUSE TestValidateToken_BoundClaimsMismatch2263=== RUN TestValidateToken_BoundSubjectMismatch2264=== PAUSE TestValidateToken_BoundSubjectMismatch2265=== RUN TestValidateToken_MultipleProviders2266=== PAUSE TestValidateToken_MultipleProviders2267=== RUN TestValidateToken_NoMatchingProvider2268=== PAUSE TestValidateToken_NoMatchingProvider2269=== RUN TestValidateToken_KubernetesServiceAccount2270=== PAUSE TestValidateToken_KubernetesServiceAccount2271=== RUN TestNewValidator_KubernetesRequiresCA2272=== PAUSE TestNewValidator_KubernetesRequiresCA2273=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2274=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2275=== RUN TestScopes_LegacyProviderDefaultsToWrite2276=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2277=== RUN TestScopes_Rules2278=== PAUSE TestScopes_Rules2279=== RUN TestScopes_ConfigValidation2280=== PAUSE TestScopes_ConfigValidation2281=== CONT TestGlobMatch2282=== CONT TestScopes_LegacyProviderDefaultsToWrite2283=== RUN TestGlobMatch/foo_foo2284=== PAUSE TestGlobMatch/foo_foo2285=== RUN TestGlobMatch/foo_bar2286=== PAUSE TestGlobMatch/foo_bar2287=== CONT TestValidateToken_NoMatchingProvider2288=== CONT TestValidateToken_KubernetesServiceAccount2289=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2290=== CONT TestValidateToken_Expired2291=== CONT TestValidateToken_MultipleProviders2292=== CONT TestValidateToken_BoundSubjectMismatch2293=== CONT TestValidateToken_BoundClaimsMismatch2294=== CONT TestValidateToken_ValidToken2295=== RUN TestGlobMatch/*_2296=== PAUSE TestGlobMatch/*_2297=== RUN TestGlobMatch/*_anything2298=== PAUSE TestGlobMatch/*_anything2299=== RUN TestGlobMatch/foo*_foo2300=== PAUSE TestGlobMatch/foo*_foo2301=== RUN TestGlobMatch/foo*_foobar2302=== PAUSE TestGlobMatch/foo*_foobar2303=== RUN TestGlobMatch/foo*_bar2304=== PAUSE TestGlobMatch/foo*_bar2305=== RUN TestGlobMatch/*bar_bar2306=== PAUSE TestGlobMatch/*bar_bar2307=== RUN TestGlobMatch/*bar_foobar2308=== PAUSE TestGlobMatch/*bar_foobar2309=== RUN TestGlobMatch/*bar_foo2310=== PAUSE TestGlobMatch/*bar_foo2311=== RUN TestGlobMatch/foo*bar_foobar2312=== PAUSE TestGlobMatch/foo*bar_foobar2313=== RUN TestGlobMatch/foo*bar_foo123bar2314=== PAUSE TestGlobMatch/foo*bar_foo123bar2315=== RUN TestGlobMatch/foo*bar_foobarbaz2316=== PAUSE TestGlobMatch/foo*bar_foobarbaz2317=== RUN TestGlobMatch/*/*_foo/bar2318=== PAUSE TestGlobMatch/*/*_foo/bar2319=== RUN TestGlobMatch/*/*_foo2320=== PAUSE TestGlobMatch/*/*_foo2321=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2322=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2323=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02324=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02325=== RUN TestGlobMatch/refs/*/main_refs/heads/main2326=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2327=== RUN TestGlobMatch/fo?_foo2328=== PAUSE TestGlobMatch/fo?_foo2329=== RUN TestGlobMatch/fo?_fo2330=== PAUSE TestGlobMatch/fo?_fo2331=== RUN TestGlobMatch/fo?_fooo2332=== PAUSE TestGlobMatch/fo?_fooo2333=== RUN TestGlobMatch/?oo_foo2334=== PAUSE TestGlobMatch/?oo_foo2335=== RUN TestGlobMatch/?oo_boo2336=== PAUSE TestGlobMatch/?oo_boo2337=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2338=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2339=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2340=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2341=== CONT TestValidateToken_WrongAudience23422026/09/10 17:37:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50542/oidc23432026/09/10 17:37:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50541/oidc23442026/09/10 17:37:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50540/oidc23452026/09/10 17:37:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50538/oidc23462026/09/10 17:37:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50537/oidc23472026/09/10 17:37:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50550/oidc23482026/09/10 17:37:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50543/oidc23492026/09/10 17:37:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50539/oidc23502026/09/10 17:37:49 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:50546/oidc23512026/09/10 17:37:49 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232352--- PASS: TestValidateToken_Expired (0.01s)2353=== CONT TestScopes_ConfigValidation2354--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2355--- PASS: TestValidateToken_WrongAudience (0.01s)2356=== CONT TestGlobMatch/foo_foo2357=== CONT TestGlobMatch/*/*_foo/bar2358=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2359=== CONT TestGlobMatch/refs/*/main_refs/heads/main2360=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02361=== CONT TestGlobMatch/fo?_foo2362=== CONT TestGlobMatch/?oo_boo2363=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2364=== CONT TestGlobMatch/?oo_foo2365=== CONT TestGlobMatch/fo?_fooo2366--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2367=== CONT TestNewValidator_KubernetesRequiresCA2368=== CONT TestScopes_Rules2369=== CONT TestAudienceForIssuer2370=== CONT TestGlobMatch/fo?_fo2371=== CONT TestGlobMatch/*bar_bar2372=== CONT TestGlobMatch/foo*bar_foobarbaz2373=== CONT TestGlobMatch/foo*_foo2374=== CONT TestGlobMatch/foo*bar_foo123bar2375=== CONT TestGlobMatch/foo*_bar2376=== CONT TestGlobMatch/foo*bar_foobar2377=== CONT TestGlobMatch/foo*_foobar2378=== CONT TestGlobMatch/*bar_foo2379=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2380=== CONT TestGlobMatch/*_2381=== CONT TestGlobMatch/foo_bar2382=== CONT TestGlobMatch/*_anything2383=== CONT TestGlobMatch/*/*_foo2384--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2385--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2386=== CONT TestGlobMatch/*bar_foobar2387--- PASS: TestAudienceForIssuer (0.00s)2388--- PASS: TestGlobMatch (0.00s)2389 --- PASS: TestGlobMatch/foo_foo (0.00s)2390 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2391 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2392 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2393 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2394 --- PASS: TestGlobMatch/fo?_foo (0.00s)2395 --- PASS: TestGlobMatch/?oo_boo (0.00s)2396 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2397 --- PASS: TestGlobMatch/?oo_foo (0.00s)2398 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2399 --- PASS: TestGlobMatch/fo?_fo (0.00s)2400 --- PASS: TestGlobMatch/*bar_bar (0.00s)2401 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2402 --- PASS: TestGlobMatch/foo*_foo (0.00s)2403 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2404 --- PASS: TestGlobMatch/foo*_bar (0.00s)2405 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2406 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2407 --- PASS: TestGlobMatch/*bar_foo (0.00s)2408 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2409 --- PASS: TestGlobMatch/*_ (0.00s)2410 --- PASS: TestGlobMatch/foo_bar (0.00s)2411 --- PASS: TestGlobMatch/*_anything (0.00s)2412 --- PASS: TestGlobMatch/*/*_foo (0.00s)2413 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2414--- PASS: TestValidateToken_MultipleProviders (0.01s)2415--- PASS: TestValidateToken_ValidToken (0.01s)24162026/09/10 17:37:49 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5054424172026/09/10 17:37:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50561/oidc2418--- PASS: TestScopes_ConfigValidation (0.00s)2419--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2420--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)24212026/09/10 17:37:49 http: TLS handshake error from 127.0.0.1:50562: remote error: tls: bad certificate2422--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2423--- PASS: TestScopes_Rules (0.01s)2424PASS2425Running hook tests...2426=== RUN TestSendPathsEmpty2427=== PAUSE TestSendPathsEmpty2428=== RUN TestQueueEnqueueAndFetch2429=== PAUSE TestQueueEnqueueAndFetch2430=== RUN TestQueueDeduplication2431=== PAUSE TestQueueDeduplication2432=== RUN TestQueueRemove2433=== PAUSE TestQueueRemove2434=== RUN TestQueueFetchBatchLimit2435=== PAUSE TestQueueFetchBatchLimit2436=== RUN TestQueueRetryMovesToBack2437=== PAUSE TestQueueRetryMovesToBack2438=== RUN TestQueueFetchRemoveLifecycle2439=== PAUSE TestQueueFetchRemoveLifecycle2440=== RUN TestQueueConcurrentWriters2441=== PAUSE TestQueueConcurrentWriters2442=== RUN TestQueueRemoveLargeClosure2443=== PAUSE TestQueueRemoveLargeClosure2444=== RUN TestServerClientIntegration2445=== PAUSE TestServerClientIntegration2446=== RUN TestServerQueueError2447=== PAUSE TestServerQueueError2448=== RUN TestGetListenerSocketActivation2449 server_test.go:210: === RUN TestGetListenerSocketActivation2450 --- PASS: TestGetListenerSocketActivation (0.00s)2451 PASS2452 2453--- PASS: TestGetListenerSocketActivation (0.01s)2454=== RUN TestDrainIsolatesPoisonPath2455=== PAUSE TestDrainIsolatesPoisonPath2456=== RUN TestRunNotBlockedByPoisonHead2457=== PAUSE TestRunNotBlockedByPoisonHead2458=== RUN TestDrainGivesUpWhenServerDown2459=== PAUSE TestDrainGivesUpWhenServerDown2460=== RUN TestFailedPathPrunedByLaterClosure2461=== PAUSE TestFailedPathPrunedByLaterClosure2462=== RUN TestWorkerUploadsAndRemoves2463=== PAUSE TestWorkerUploadsAndRemoves2464=== RUN TestWorkerSkipsGCdPaths2465=== PAUSE TestWorkerSkipsGCdPaths2466=== RUN TestWorkerPrunesClosureDeps2467=== PAUSE TestWorkerPrunesClosureDeps2468=== RUN TestDrainTimeout2469=== PAUSE TestDrainTimeout2470=== CONT TestSendPathsEmpty2471=== CONT TestServerQueueError2472=== CONT TestWorkerUploadsAndRemoves2473=== CONT TestDrainTimeout2474=== CONT TestWorkerPrunesClosureDeps2475=== CONT TestWorkerSkipsGCdPaths2476=== CONT TestDrainGivesUpWhenServerDown2477=== CONT TestFailedPathPrunedByLaterClosure2478=== CONT TestRunNotBlockedByPoisonHead2479=== CONT TestQueueRetryMovesToBack2480=== CONT TestServerClientIntegration2481--- PASS: TestSendPathsEmpty (0.00s)24822026/09/10 17:37:50 ERROR Failed to queue paths error="permission denied" count=12483--- PASS: TestServerQueueError (0.00s)2484=== CONT TestQueueFetchBatchLimit2485--- PASS: TestServerClientIntegration (0.00s)2486=== CONT TestQueueRemove24872026/09/10 17:37:50 INFO Upload queue status pending=224882026/09/10 17:37:50 INFO Upload queue status pending=224892026/09/10 17:37:50 INFO Uploading batch count=124902026/09/10 17:37:50 INFO Uploading batch count=22491--- PASS: TestQueueFetchBatchLimit (0.01s)2492=== CONT TestQueueDeduplication24932026/09/10 17:37:50 INFO Uploading batch count=224942026/09/10 17:37:50 INFO Uploading batch count=124952026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=124962026/09/10 17:37:50 INFO Upload queue status pending=224972026/09/10 17:37:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-99968-1879214675/TestWorkerSkipsGCdPaths2685607513/002/nonexistent24982026/09/10 17:37:50 INFO Uploading batch count=124992026/09/10 17:37:50 INFO Upload queue status pending=325002026/09/10 17:37:50 INFO Uploading batch count=225012026/09/10 17:37:50 INFO Uploading batch count=125022026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=225032026/09/10 17:37:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99968-1879214675/TestDrainGivesUpWhenServerDown2976729376/002/a25042026/09/10 17:37:50 INFO Uploading batch count=125052026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=12506--- PASS: TestQueueRetryMovesToBack (0.01s)2507=== CONT TestQueueRemoveLargeClosure25082026/09/10 17:37:50 INFO Uploading batch count=125092026/09/10 17:37:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99968-1879214675/TestDrainGivesUpWhenServerDown2976729376/002/b2510--- PASS: TestQueueRemove (0.01s)2511=== CONT TestQueueConcurrentWriters25122026/09/10 17:37:50 INFO Uploading batch count=225132026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=225142026/09/10 17:37:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99968-1879214675/TestDrainGivesUpWhenServerDown2976729376/002/c25152026/09/10 17:37:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99968-1879214675/TestDrainGivesUpWhenServerDown2976729376/002/d25162026/09/10 17:37:50 INFO Uploading batch count=225172026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=225182026/09/10 17:37:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99968-1879214675/TestDrainGivesUpWhenServerDown2976729376/002/e25192026/09/10 17:37:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99968-1879214675/TestDrainGivesUpWhenServerDown2976729376/002/f25202026/09/10 17:37:50 ERROR Drain finished with paths left in queue remaining=102521--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2522=== CONT TestQueueEnqueueAndFetch2523--- PASS: TestQueueDeduplication (0.00s)2524=== CONT TestQueueFetchRemoveLifecycle2525--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2526=== CONT TestDrainIsolatesPoisonPath2527--- PASS: TestQueueEnqueueAndFetch (0.00s)25282026/09/10 17:37:50 INFO Uploading batch count=425292026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=425302026/09/10 17:37:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-99968-1879214675/TestDrainIsolatesPoisonPath3147759730/002/bbb2531--- PASS: TestQueueFetchRemoveLifecycle (0.00s)25322026/09/10 17:37:50 INFO Uploading batch count=125332026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=125342026/09/10 17:37:50 INFO Uploading batch count=125352026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=125362026/09/10 17:37:50 INFO Uploading batch count=125372026/09/10 17:37:50 ERROR Upload failed error="upload failed" count=125382026/09/10 17:37:50 ERROR Drain finished with paths left in queue remaining=12539--- PASS: TestDrainIsolatesPoisonPath (0.00s)2540--- PASS: TestWorkerSkipsGCdPaths (0.03s)2541--- PASS: TestWorkerPrunesClosureDeps (0.03s)2542--- PASS: TestWorkerUploadsAndRemoves (0.03s)2543--- PASS: TestQueueRemoveLargeClosure (0.04s)2544--- PASS: TestQueueConcurrentWriters (0.15s)25452026/09/10 17:37:50 ERROR Upload failed error="context deadline exceeded" count=225462026/09/10 17:37:50 ERROR Drain finished with paths left in queue remaining=42547--- PASS: TestDrainTimeout (0.21s)25482026/09/10 17:37:51 INFO Uploading batch count=125492026/09/10 17:37:51 INFO Uploading batch count=125502026/09/10 17:37:51 INFO Uploading batch count=125512026/09/10 17:37:51 ERROR Upload failed error="upload failed" count=125522026/09/10 17:37:51 INFO Uploading batch count=125532026/09/10 17:37:51 ERROR Upload failed error="upload failed" count=125542026/09/10 17:37:51 INFO Uploading batch count=125552026/09/10 17:37:51 ERROR Upload failed error="upload failed" count=125562026/09/10 17:37:51 INFO Uploading batch count=125572026/09/10 17:37:51 ERROR Upload failed error="upload failed" count=125582026/09/10 17:37:51 ERROR Drain finished with paths left in queue remaining=12559--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2560PASS