niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #236
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestSetClientTLS66=== PAUSE TestSetClientTLS67=== RUN TestSetClientTLSDoesNotMutateDefaultTransport68=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport69=== RUN TestSetClientTLSErrors70=== PAUSE TestSetClientTLSErrors71=== RUN TestStaticToken72=== PAUSE TestStaticToken73=== RUN TestFileTokenReadsAndCaches74=== PAUSE TestFileTokenReadsAndCaches75=== RUN TestFileTokenMissing76=== PAUSE TestFileTokenMissing77=== RUN TestFileTokenEmpty78=== PAUSE TestFileTokenEmpty79=== RUN TestScriptTokenNoExpiryRerunsEveryCall80=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall81=== RUN TestScriptTokenCachesUntilRefresh82=== PAUSE TestScriptTokenCachesUntilRefresh83=== RUN TestScriptTokenEmptyToken84=== PAUSE TestScriptTokenEmptyToken85=== RUN TestScriptTokenBadJSON86=== PAUSE TestScriptTokenBadJSON87=== RUN TestScriptTokenScriptFails88=== PAUSE TestScriptTokenScriptFails89=== RUN TestScriptTokenEmptyCommand90=== PAUSE TestScriptTokenEmptyCommand91=== CONT TestDoServerRequestAttachesToken92=== CONT TestDoWithRetry_BodyReplayedViaGetBody93=== CONT TestStreamPushGivesUpOnDeadServer94=== CONT TestSetClientTLSErrors95=== CONT TestSetClientTLSDoesNotMutateDefaultTransport962026/09/21 14:06:02 ERROR Upload failed error="connection refused" count=20972026/09/21 14:06:02 ERROR Server seems unavailable, giving up on batch untried=1798=== CONT TestSetClientTLS99=== CONT TestStreamPushRequestLine100=== CONT TestScriptTokenScriptFails101--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)102=== CONT TestEncodeNixBase32103=== RUN TestEncodeNixBase32/test_string_hash104=== PAUSE TestEncodeNixBase32/test_string_hash105=== CONT TestScriptTokenEmptyCommand106=== CONT TestResolveStorePath107=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess108=== CONT TestRateLimiterFeedback109=== CONT TestPathInfoCACompatibility110=== CONT TestParsePathInfoJSONMultiplePaths111=== CONT TestParsePathInfoJSON112=== CONT TestPathInfoHashCompatibility113=== CONT TestGetStorePathHash114=== CONT TestConvertHashToNix32115=== CONT TestStreamPushReportsEveryPath116=== CONT TestStreamPushIsolatesFailures117=== CONT TestStreamPushBatchesUnderLoad118=== CONT TestUploadMultipart_SupersededByPeer119=== CONT TestStaticToken120=== RUN TestEncodeNixBase32/empty_input121=== CONT TestEncodeNixBase32WithRealHash122--- PASS: TestEncodeNixBase32WithRealHash (0.00s)123=== RUN TestConvertHashToNix32/SRI_format_to_Nix321242026/09/21 14:06:02 WARN Rate limiter enabled after throttle name=server-test rate=5125=== RUN TestRateLimiterFeedback/429_enables_limiter1262026/09/21 14:06:02 ERROR Upload failed error=boom count=1127=== CONT TestDumpPathWriterError128--- PASS: TestScriptTokenEmptyCommand (0.00s)129=== CONT TestDumpPathSingleFile130=== PAUSE TestEncodeNixBase32/empty_input1312026/09/21 14:06:02 ERROR Upload failed error="bad path" count=3132=== RUN TestParsePathInfoJSON/Nix_format133=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths134=== PAUSE TestParsePathInfoJSON/Nix_format135=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== RUN TestParsePathInfoJSON/Lix_format137=== CONT TestScriptTokenNoExpiryRerunsEveryCall138=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths139=== RUN TestGetStorePathHash/valid_store_path140=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths141=== CONT TestDumpPathMatchesNix142--- PASS: TestStaticToken (0.00s)143=== RUN TestUploadMultipart_SupersededByPeer/exists144=== CONT TestFileTokenReadsAndCaches145=== PAUSE TestParsePathInfoJSON/Lix_format146=== RUN TestPathInfoCACompatibility/null_ca_field147=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== PAUSE TestPathInfoCACompatibility/null_ca_field149=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32151=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1522026/09/21 14:06:02 WARN Rate limiter enabled after throttle name=server-test rate=5153=== PAUSE TestRateLimiterFeedback/429_enables_limiter154=== CONT TestFileTokenEmpty155=== PAUSE TestGetStorePathHash/valid_store_path156--- PASS: TestStreamPushIsolatesFailures (0.00s)157=== CONT TestShellSplit158=== CONT TestFileTokenMissing159=== PAUSE TestUploadMultipart_SupersededByPeer/exists160=== RUN TestSetClientTLSErrors/missing_cert_file161=== CONT TestShellSplitErrors162=== RUN TestPathInfoCACompatibility/old_string_format_-_text163=== RUN TestGetStorePathHash/basename_without_hyphen_should_error164=== RUN TestConvertHashToNix32/already_Nix32_format165=== CONT TestScriptTokenBadJSON1662026/09/21 14:06:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34455167=== PAUSE TestSetClientTLSErrors/missing_cert_file168=== CONT TestFilterOversizedClosures169=== RUN TestParsePathInfoJSON/empty_input170=== PAUSE TestParsePathInfoJSON/empty_input171=== RUN TestParsePathInfoJSON/whitespace_only172=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text173=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error174--- PASS: TestScriptTokenScriptFails (0.00s)175--- PASS: TestResolveStorePath (0.00s)176--- PASS: TestStreamPushReportsEveryPath (0.01s)177--- PASS: TestShellSplit (0.00s)178--- PASS: TestShellSplitErrors (0.00s)179=== RUN TestUploadMultipart_SupersededByPeer/missing180=== PAUSE TestUploadMultipart_SupersededByPeer/missing181=== PAUSE TestConvertHashToNix32/already_Nix32_format182=== RUN TestRateLimiterFeedback/503_enables_limiter183=== RUN TestSetClientTLSErrors/missing_key_file184=== RUN TestFilterOversizedClosures/no_limit_keeps_everything185=== PAUSE TestRateLimiterFeedback/503_enables_limiter186=== CONT TestScriptTokenEmptyToken187=== PAUSE TestParsePathInfoJSON/whitespace_only188=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon190=== CONT TestPartSizeForNAR191=== RUN TestParsePathInfoJSON/invalid_JSON192=== RUN TestPartSizeForNAR/zero_stays_at_minimum193=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum194=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter195=== RUN TestPartSizeForNAR/small_stays_at_minimum196=== PAUSE TestPartSizeForNAR/small_stays_at_minimum197=== CONT TestUploadMultipart_PartsInParallel198=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1992026/09/21 14:06:02 WARN Rate limiter backed off name=server-test rate=5200=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2012026/09/21 14:06:02 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34455202=== RUN TestConvertHashToNix32/invalid_format203=== RUN TestSetClientTLS/rejects_connection_without_client_cert204=== PAUSE TestSetClientTLSErrors/missing_key_file205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive206=== RUN TestSetClientTLSErrors/missing_ca_file207=== PAUSE TestSetClientTLSErrors/missing_ca_file208=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI209--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)210=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything211=== PAUSE TestParsePathInfoJSON/invalid_JSON212=== RUN TestSetClientTLSErrors/invalid_ca_file213=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter214=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum215=== CONT TestScriptTokenCachesUntilRefresh216=== CONT TestEncodeNixBase32/test_string_hash217=== CONT TestCaseHackSuffix218=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert219=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error220=== PAUSE TestConvertHashToNix32/invalid_format221=== RUN TestPathInfoCACompatibility/new_structured_format_-_text222=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text223=== CONT TestUploadMultipart_SupersededByPeer/exists224=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method225=== CONT TestUploadMultipart_SupersededByPeer/missing226=== CONT TestParsePathInfoJSON/Nix_format227=== CONT TestParsePathInfoJSON/whitespace_only228=== CONT TestParsePathInfoJSON/empty_input229=== CONT TestParsePathInfoJSON/Lix_format230=== CONT TestParsePathInfoJSON/invalid_JSON231=== CONT TestConvertHashToNix32/SRI_format_to_Nix32232=== CONT TestConvertHashToNix32/invalid_format233=== CONT TestConvertHashToNix32/already_Nix32_format234=== CONT TestRegisterUploadedObjectReusesConnections235=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI236=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped237=== CONT TestEncodeNixBase32/empty_input238=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method239=== CONT TestPathInfoCACompatibility/null_ca_field240=== CONT TestPathInfoCACompatibility/new_structured_format_-_text241=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512242=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter243=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum244=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths245=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths246=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA247=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error248=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error249--- PASS: TestDoServerRequestAttachesToken (0.01s)250=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts251=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts252=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter253=== CONT TestRateLimiterFeedback/503_enables_limiter254=== CONT TestGetStorePathHash/valid_store_path255=== PAUSE TestSetClientTLSErrors/invalid_ca_file256=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method257=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive258=== CONT TestPathInfoCACompatibility/old_string_format_-_text259=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error260=== CONT TestGetStorePathHash/basename_without_hyphen_should_error261=== CONT TestSetClientTLSErrors/missing_cert_file262=== RUN TestPartSizeForNAR/1_TiB263=== PAUSE TestPartSizeForNAR/1_TiB264=== CONT TestSetClientTLSErrors/missing_ca_file265=== RUN TestPartSizeForNAR/5_TiB_S3_max_object266=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object267=== RUN TestPartSizeForNAR/capped_at_5_GiB268=== PAUSE TestPartSizeForNAR/capped_at_5_GiB269=== CONT TestPartSizeForNAR/zero_stays_at_minimum270=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped271=== RUN TestFilterOversizedClosures/all_closures_skipped272=== PAUSE TestFilterOversizedClosures/all_closures_skipped273=== CONT TestFilterOversizedClosures/no_limit_keeps_everything274=== CONT TestRateLimiterFeedback/429_enables_limiter275=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512276=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)277=== CONT TestPartSizeForNAR/small_stays_at_minimum278=== CONT TestFilterOversizedClosures/all_closures_skipped279=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2802026/09/21 14:06:02 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=502812026/09/21 14:06:02 WARN Rate limiter enabled after throttle name=server-test rate=52822026/09/21 14:06:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44769283=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2842026/09/21 14:06:02 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000285=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon286=== CONT TestPartSizeForNAR/capped_at_5_GiB287=== CONT TestSetClientTLSErrors/invalid_ca_file288=== CONT TestSetClientTLSErrors/missing_key_file2892026/09/21 14:06:02 WARN Rate limiter enabled after throttle name=server-test rate=52902026/09/21 14:06:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:44361291=== CONT TestPartSizeForNAR/1_TiB292=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts2932026/09/21 14:06:02 WARN Rate limiter backed off name=server-test rate=5294=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum295--- PASS: TestFileTokenReadsAndCaches (0.00s)296--- PASS: TestFileTokenMissing (0.00s)297--- PASS: TestFileTokenEmpty (0.00s)298=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122992026/09/21 14:06:02 WARN Rate limiter backed off name=server-test rate=5300--- PASS: TestScriptTokenBadJSON (0.00s)301=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error302=== CONT TestPartSizeForNAR/5_TiB_S3_max_object303--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)304--- PASS: TestScriptTokenEmptyToken (0.03s)305--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)306--- PASS: TestParsePathInfoJSON (0.01s)307 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)308 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)309 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)310 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)311 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)312--- PASS: TestConvertHashToNix32 (0.04s)313 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)314 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)315 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)316--- PASS: TestDumpPathSingleFile (0.04s)317--- PASS: TestEncodeNixBase32 (0.00s)318 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)319 --- PASS: TestEncodeNixBase32/empty_input (0.00s)320--- PASS: TestGetStorePathHash (0.05s)321 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)322 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)323 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)324 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)325=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter326--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)327 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)328 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)329=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA330--- PASS: TestFilterOversizedClosures (0.05s)331 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)332 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)333 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)334--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)335 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)336 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)337--- PASS: TestPartSizeForNAR (0.04s)338 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)339 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)340 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)341 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)342 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)343 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)344 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)345--- PASS: TestPathInfoHashCompatibility (0.06s)346 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)347 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)348 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)349 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)350=== RUN TestSetClientTLS/preserves_debug_logging_transport351--- PASS: TestPathInfoCACompatibility (0.04s)352 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)353 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)354 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)355 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)356 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)357=== PAUSE TestSetClientTLS/preserves_debug_logging_transport358=== CONT TestSetClientTLS/rejects_connection_without_client_cert359=== CONT TestSetClientTLS/preserves_debug_logging_transport360=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA361--- PASS: TestRateLimiterFeedback (0.04s)362 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)363 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)364 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)365 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)366--- PASS: TestSetClientTLSErrors (0.06s)367 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)368 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)369 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)370 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)371--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)3722026/09/21 14:06:02 http: TLS handshake error from 127.0.0.1:47410: remote error: tls: bad certificate373--- PASS: TestSetClientTLS (0.06s)374 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)375 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)376 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)377--- PASS: TestStreamPushRequestLine (0.07s)378--- PASS: TestCaseHackSuffix (0.06s)379--- PASS: TestDumpPathWriterError (0.08s)380--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)381--- PASS: TestStreamPushBatchesUnderLoad (0.11s)382--- PASS: TestDumpPathMatchesNix (0.12s)383--- PASS: TestUploadMultipart_PartsInParallel (0.65s)384--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)385PASS386Running server tests...387The files belonging to this database system will be owned by user "nixbld".388This user must also own the server process.389390The database cluster will be initialized with locale "C".391The default database encoding has accordingly been set to "SQL_ASCII".392The default text search configuration will be set to "english".393394Data page checksums are enabled.395396creating directory /build/postgres4157334776/data ... ok397creating subdirectories ... ok398selecting dynamic shared memory implementation ... posix399selecting default "max_connections" ... 100400selecting default "shared_buffers" ... 128MB401selecting default time zone ... UTC402creating configuration files ... ok403running bootstrap script ... ok404performing post-bootstrap initialization ... ok405syncing data to disk ... ok406407initdb: warning: enabling "trust" authentication for local connections408initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.409410Success. You can now start the database server using:411412 pg_ctl -D /build/postgres4157334776/data -l logfile start413414/build/postgres4157334776:5432 - no response4152026-09-21 14:06:04.608 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4162026-09-21 14:06:04.608 UTC [129] LOG: listening on Unix socket "/build/postgres4157334776/.s.PGSQL.5432"4172026-09-21 14:06:04.613 UTC [136] LOG: database system was shut down at 2026-09-21 14:06:04 UTC4182026-09-21 14:06:04.617 UTC [129] LOG: database system is ready to accept connections419/build/postgres4157334776:5432 - accepting connections420{"timestamp":"2026-09-21T14:06:04.916872509Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4bffbc79-b8fb-4961-88f6-b0a97fddc70c","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":430,"threadName":"rustfs-worker","threadId":"ThreadId(399)"}421=== RUN TestService_AuthMiddleware422=== PAUSE TestService_AuthMiddleware423=== RUN TestService_AuthMiddleware_MTLSProxyHeader424=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader425=== RUN TestService_AuthMiddleware_MTLSBoundSubjects426=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects427=== RUN TestService_ReadAuthMiddleware428=== PAUSE TestService_ReadAuthMiddleware429=== RUN TestService_AuthMiddleware_OIDC430=== PAUSE TestService_AuthMiddleware_OIDC431=== RUN TestService_RequireScope_OIDC432=== PAUSE TestService_RequireScope_OIDC433=== RUN TestService_ReadScope_PublicByDefault434=== PAUSE TestService_ReadScope_PublicByDefault435=== RUN TestCacheConfigHandler436=== PAUSE TestCacheConfigHandler437=== RUN TestCacheStatsHandler438=== PAUSE TestCacheStatsHandler439=== RUN TestClientCADerivations440=== PAUSE TestClientCADerivations441=== RUN TestClientErrorHandling442=== PAUSE TestClientErrorHandling443=== RUN TestClientIntegration444=== PAUSE TestClientIntegration445=== RUN TestClientMultipleUploads446=== PAUSE TestClientMultipleUploads447=== RUN TestClientWithDependencies448=== PAUSE TestClientWithDependencies449=== RUN TestClientSharedPathCommittedMidPush450=== PAUSE TestClientSharedPathCommittedMidPush451=== RUN TestPinProtectsFromGC452=== PAUSE TestPinProtectsFromGC453=== RUN TestResolveDBConnectionString454=== PAUSE TestResolveDBConnectionString455=== RUN TestLeadElectsOneAndHandsOver456=== PAUSE TestLeadElectsOneAndHandsOver457=== RUN TestLeadIncumbentWinsAfterRestart4582026-09-21 14:06:05.112 UTC [564] ERROR: relation "goose_db_version" does not exist at character 364592026-09-21 14:06:05.112 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4602026/09/21 14:06:05 OK 20241026095416_initial_model.sql (6.25ms)4612026/09/21 14:06:05 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)4622026/09/21 14:06:05 OK 20251218171726_add_pins.sql (2.04ms)4632026/09/21 14:06:05 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)4642026/09/21 14:06:05 OK 20260905000000_add_claims.sql (2.46ms)4652026/09/21 14:06:05 OK 20260920000000_drop_claims.sql (1.36ms)4662026/09/21 14:06:05 goose: successfully migrated database to version: 202609200000004672026/09/21 14:06:05 OK 1_commit_pending_closure.sql (1.37ms)4682026/09/21 14:06:05 OK 2_object_stats_trigger.sql (692.08µs)4692026/09/21 14:06:05 goose: up to current file version: 24702026/09/21 14:06:05 INFO lead: acquired remote=192.0.2.1:12344712026/09/21 14:06:05 INFO lead: released remote=192.0.2.1:12344722026/09/21 14:06:05 INFO lead: acquired remote=192.0.2.1:12344732026/09/21 14:06:05 INFO lead: released remote=192.0.2.1:1234474--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)475=== RUN TestLeadEndsOnShutdown476=== PAUSE TestLeadEndsOnShutdown477=== RUN TestGCAdvisoryLockBlocksConcurrentRun4782026-09-21 14:06:05.879 UTC [574] ERROR: relation "goose_db_version" does not exist at character 364792026-09-21 14:06:05.879 UTC [574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4802026/09/21 14:06:05 OK 20241026095416_initial_model.sql (5.99ms)4812026/09/21 14:06:05 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)4822026/09/21 14:06:05 OK 20251218171726_add_pins.sql (2.43ms)4832026/09/21 14:06:05 OK 20260628120000_add_object_size_and_stats.sql (1.96ms)4842026/09/21 14:06:05 OK 20260905000000_add_claims.sql (2.28ms)4852026/09/21 14:06:05 OK 20260920000000_drop_claims.sql (1.45ms)4862026/09/21 14:06:05 goose: successfully migrated database to version: 202609200000004872026/09/21 14:06:05 OK 1_commit_pending_closure.sql (1.32ms)4882026/09/21 14:06:05 OK 2_object_stats_trigger.sql (646.24µs)4892026/09/21 14:06:05 goose: up to current file version: 2490--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)491=== RUN TestGCBugBareHashReferences492=== PAUSE TestGCBugBareHashReferences493=== RUN TestGCMetrics494=== PAUSE TestGCMetrics495=== RUN TestGCTaskStore_StartNew496=== PAUSE TestGCTaskStore_StartNew497=== RUN TestGCTaskStore_DeduplicateSameParams498=== PAUSE TestGCTaskStore_DeduplicateSameParams499=== RUN TestGCTaskStore_ConflictDifferentParams500=== PAUSE TestGCTaskStore_ConflictDifferentParams501=== RUN TestGCTaskStore_GetEmpty502=== PAUSE TestGCTaskStore_GetEmpty503=== RUN TestGCTaskStore_GetReturnsLatest504=== PAUSE TestGCTaskStore_GetReturnsLatest505=== RUN TestGCTaskStore_CompletedAllowsNewTask506=== PAUSE TestGCTaskStore_CompletedAllowsNewTask507=== RUN TestGCTaskStore_PhaseUpdates508=== PAUSE TestGCTaskStore_PhaseUpdates509=== RUN TestGCTaskStore_Fail510=== PAUSE TestGCTaskStore_Fail511=== RUN TestGracefulShutdownDrainsInflight512=== PAUSE TestGracefulShutdownDrainsInflight513=== RUN TestService_healthCheckHandler514=== PAUSE TestService_healthCheckHandler515=== RUN TestService_readinessHandler516=== PAUSE TestService_readinessHandler517=== RUN TestGenerateLandingPage518=== PAUSE TestGenerateLandingPage519=== RUN TestCacheConfigHandlerMaxNarSize520=== PAUSE TestCacheConfigHandlerMaxNarSize521=== RUN TestCreatePendingClosureRejectsOversizedNAR522=== PAUSE TestCreatePendingClosureRejectsOversizedNAR523=== RUN TestNARDeduplicationMetadataUploadBug524=== PAUSE TestNARDeduplicationMetadataUploadBug525=== RUN TestMetricsInventory526=== PAUSE TestMetricsInventory527=== RUN TestService_NativeMTLS528=== PAUSE TestService_NativeMTLS529=== RUN TestServerTLSConfig530=== PAUSE TestServerTLSConfig531=== RUN TestMultipartCleanup532=== PAUSE TestMultipartCleanup533=== RUN TestObjectStatsTrigger534=== PAUSE TestObjectStatsTrigger535=== RUN TestOrphanedObjectsGC536=== PAUSE TestOrphanedObjectsGC537=== RUN TestOrphanedObjectsGCStressTest538=== PAUSE TestOrphanedObjectsGCStressTest539=== RUN TestResurrectedObjectNotDeleted540=== PAUSE TestResurrectedObjectNotDeleted541=== RUN TestParseSingleRange542=== PAUSE TestParseSingleRange543=== RUN TestIsValidCachePath544=== PAUSE TestIsValidCachePath545=== RUN TestReadProxyNarinfo546=== PAUSE TestReadProxyNarinfo547=== RUN TestReadProxyNarinfoAlreadyDecompressed548=== PAUSE TestReadProxyNarinfoAlreadyDecompressed549=== RUN TestReadProxyNarStreaming550=== PAUSE TestReadProxyNarStreaming551=== RUN TestReadProxy404552=== PAUSE TestReadProxy404553=== RUN TestReadProxyInvalidPath554=== PAUSE TestReadProxyInvalidPath555=== RUN TestReadProxyHead556=== PAUSE TestReadProxyHead557=== RUN TestReadProxyConditionalGet558=== PAUSE TestReadProxyConditionalGet559=== RUN TestReadProxyRootRedirectsToIndexHTML560=== PAUSE TestReadProxyRootRedirectsToIndexHTML561=== RUN TestReadProxyDisabled562=== PAUSE TestReadProxyDisabled563=== RUN TestReadRedirectNar564=== PAUSE TestReadRedirectNar565=== RUN TestReadRedirectKeepsNarinfoProxied566=== PAUSE TestReadRedirectKeepsNarinfoProxied567=== RUN TestReadProxyRangeRequest568=== PAUSE TestReadProxyRangeRequest569=== RUN TestReadRedirectUsesPublicS3URL570=== PAUSE TestReadRedirectUsesPublicS3URL571=== RUN TestRedundantMultipartUpload572=== PAUSE TestRedundantMultipartUpload573=== RUN TestCompleteMultipartUpload_ErrorButObjectExists574=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists575=== RUN TestCompletedNarNotReofferedAcrossClosures576=== PAUSE TestCompletedNarNotReofferedAcrossClosures577=== RUN TestPresignedUploadRegisteredBeforeCommit578=== PAUSE TestPresignedUploadRegisteredBeforeCommit579=== RUN TestService_Rustfstest580=== PAUSE TestService_Rustfstest581=== RUN TestParseSize582=== PAUSE TestParseSize583=== RUN TestSkippedUploadsHandler584=== PAUSE TestSkippedUploadsHandler585=== RUN TestSystemdListenerNotActivated586--- PASS: TestSystemdListenerNotActivated (0.00s)587=== RUN TestWatchdogBeatsWhenHealthy588--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)589=== RUN TestWatchdogSkipsWhenUnhealthy5902026/09/21 14:06:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5912026/09/21 14:06:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5972026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5982026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5992026/09/21 14:06:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"600--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)601=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle602=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle603=== RUN TestProxyWriteTimeout604=== PAUSE TestProxyWriteTimeout605=== RUN TestIsValidUploadKey606=== PAUSE TestIsValidUploadKey607=== RUN TestUploadHandlersRejectInvalidKeys608=== PAUSE TestUploadHandlersRejectInvalidKeys609=== RUN TestUploadHandlersRejectOversizedBody610=== PAUSE TestUploadHandlersRejectOversizedBody611=== RUN TestService_cleanupPendingClosuresHandler612=== PAUSE TestService_cleanupPendingClosuresHandler613=== RUN TestService_createPendingClosureHandler614=== PAUSE TestService_createPendingClosureHandler615=== RUN TestService_verifyS3Integrity616=== PAUSE TestService_verifyS3Integrity617=== RUN TestCompleteMultipartUnregistered618=== PAUSE TestCompleteMultipartUnregistered619=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT620=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT621=== CONT TestService_AuthMiddleware622=== CONT TestService_verifyS3Integrity623=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT624=== CONT TestCompleteMultipartUnregistered625=== CONT TestService_NativeMTLS626=== CONT TestService_createPendingClosureHandler627=== CONT TestService_cleanupPendingClosuresHandler628=== CONT TestUploadHandlersRejectOversizedBody629=== CONT TestUploadHandlersRejectInvalidKeys630=== CONT TestIsValidUploadKey631=== CONT TestProxyWriteTimeout632=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== CONT TestSkippedUploadsHandler634=== CONT TestParseSize635--- PASS: TestParseSize (0.00s)636=== CONT TestOrphanedObjectsGCStressTest637=== CONT TestService_Rustfstest6382026/09/21 14:06:06 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000639=== CONT TestPresignedUploadRegisteredBeforeCommit640=== CONT TestCompletedNarNotReofferedAcrossClosures641=== CONT TestCompleteMultipartUpload_ErrorButObjectExists642=== CONT TestRedundantMultipartUpload643=== CONT TestReadProxyNarinfoAlreadyDecompressed644=== CONT TestReadProxyNarinfo645=== CONT TestIsValidCachePath646=== RUN TestIsValidCachePath/narinfo647=== CONT TestParseSingleRange648=== CONT TestResurrectedObjectNotDeleted649=== RUN TestProxyWriteTimeout/narinfo650=== RUN TestIsValidUploadKey/narinfo651=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info652=== PAUSE TestIsValidCachePath/narinfo653=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars654--- PASS: TestSkippedUploadsHandler (0.01s)655=== PAUSE TestProxyWriteTimeout/narinfo656=== RUN TestParseSingleRange/none657=== PAUSE TestParseSingleRange/none658=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars659=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info660=== PAUSE TestIsValidUploadKey/narinfo661=== CONT TestOrphanedObjectsGC662=== RUN TestProxyWriteTimeout/1_GiB_nar663=== PAUSE TestProxyWriteTimeout/1_GiB_nar664=== RUN TestProxyWriteTimeout/10_GiB_nar665=== PAUSE TestProxyWriteTimeout/10_GiB_nar666=== RUN TestParseSingleRange/unknown_unit667=== PAUSE TestParseSingleRange/unknown_unit668=== RUN TestIsValidCachePath/nar_zst669=== PAUSE TestIsValidCachePath/nar_zst670=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal671=== RUN TestIsValidUploadKey/nar_zst672=== RUN TestProxyWriteTimeout/unknown_size673=== PAUSE TestProxyWriteTimeout/unknown_size674=== RUN TestParseSingleRange/multi-range_ignored675=== CONT TestObjectStatsTrigger676=== RUN TestIsValidCachePath/nar_xz677=== PAUSE TestIsValidCachePath/nar_xz678=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal679=== PAUSE TestIsValidUploadKey/nar_zst680=== RUN TestIsValidUploadKey/nar_xz681=== PAUSE TestIsValidUploadKey/nar_xz682=== RUN TestIsValidUploadKey/nar_plain683=== PAUSE TestIsValidUploadKey/nar_plain684=== RUN TestIsValidUploadKey/listing685=== PAUSE TestIsValidUploadKey/listing686=== PAUSE TestParseSingleRange/multi-range_ignored687=== RUN TestIsValidCachePath/nar_bz2688=== PAUSE TestIsValidCachePath/nar_bz2689=== RUN TestIsValidCachePath/nar_uncompressed690=== PAUSE TestIsValidCachePath/nar_uncompressed691=== RUN TestIsValidCachePath/ls692=== PAUSE TestIsValidCachePath/ls693=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key694=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key695=== RUN TestIsValidUploadKey/build_log696=== PAUSE TestIsValidUploadKey/build_log697=== RUN TestIsValidUploadKey/build_log_home-manager_file698=== PAUSE TestIsValidUploadKey/build_log_home-manager_file699=== RUN TestIsValidUploadKey/build_log_plus_in_name700=== PAUSE TestIsValidUploadKey/build_log_plus_in_name701=== RUN TestParseSingleRange/malformed_no_dash702=== PAUSE TestParseSingleRange/malformed_no_dash703=== RUN TestParseSingleRange/malformed_both_empty704=== PAUSE TestParseSingleRange/malformed_both_empty705=== RUN TestParseSingleRange/malformed_end_before_start706=== PAUSE TestParseSingleRange/malformed_end_before_start707=== RUN TestParseSingleRange/closed708=== PAUSE TestParseSingleRange/closed709=== RUN TestParseSingleRange/open-ended710=== PAUSE TestParseSingleRange/open-ended711=== RUN TestIsValidCachePath/log712=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key713=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key714=== PAUSE TestIsValidCachePath/log715=== RUN TestIsValidUploadKey/build_log_question_mark716=== PAUSE TestIsValidUploadKey/build_log_question_mark717=== RUN TestIsValidUploadKey/build_log_equals718=== PAUSE TestIsValidUploadKey/build_log_equals719=== RUN TestIsValidUploadKey/realisation720=== PAUSE TestIsValidUploadKey/realisation721=== RUN TestIsValidUploadKey/realisation_plus_in_output722=== RUN TestParseSingleRange/end_clamped_to_size723=== PAUSE TestParseSingleRange/end_clamped_to_size724=== CONT TestMultipartCleanup725=== RUN TestIsValidCachePath/realisation726=== PAUSE TestIsValidCachePath/realisation727=== PAUSE TestIsValidUploadKey/realisation_plus_in_output728=== RUN TestIsValidUploadKey/nix-cache-info729=== PAUSE TestIsValidUploadKey/nix-cache-info730=== RUN TestParseSingleRange/suffix731=== PAUSE TestParseSingleRange/suffix732=== RUN TestParseSingleRange/suffix_exceeds_size733=== PAUSE TestParseSingleRange/suffix_exceeds_size734=== RUN TestParseSingleRange/single_byte735=== PAUSE TestParseSingleRange/single_byte736=== RUN TestParseSingleRange/start_past_EOF737=== RUN TestIsValidCachePath/nix-cache-info738=== PAUSE TestIsValidCachePath/nix-cache-info739=== RUN TestIsValidCachePath/index.html740=== PAUSE TestIsValidCachePath/index.html741=== RUN TestIsValidCachePath/traversal_parent742=== PAUSE TestIsValidCachePath/traversal_parent743=== RUN TestIsValidCachePath/traversal_in_middle744=== PAUSE TestIsValidCachePath/traversal_in_middle745=== RUN TestIsValidCachePath/invalid_char_e746=== PAUSE TestIsValidCachePath/invalid_char_e747=== RUN TestIsValidCachePath/invalid_char_u748=== PAUSE TestIsValidCachePath/invalid_char_u749=== RUN TestIsValidCachePath/random_path750=== PAUSE TestIsValidCachePath/random_path751=== RUN TestIsValidCachePath/empty752=== PAUSE TestIsValidCachePath/empty753=== RUN TestIsValidCachePath/leading_slash754=== RUN TestIsValidUploadKey/index.html755=== PAUSE TestParseSingleRange/start_past_EOF756=== RUN TestParseSingleRange/start_far_past_EOF757=== PAUSE TestParseSingleRange/start_far_past_EOF758=== PAUSE TestIsValidCachePath/leading_slash759=== PAUSE TestIsValidUploadKey/index.html760=== CONT TestServerTLSConfig761=== RUN TestServerTLSConfig/no_client_CA762=== PAUSE TestServerTLSConfig/no_client_CA763=== RUN TestIsValidCachePath/wrong_extension764=== PAUSE TestIsValidCachePath/wrong_extension765=== RUN TestIsValidCachePath/short_hash766=== PAUSE TestIsValidCachePath/short_hash767=== RUN TestIsValidUploadKey/narinfo_key,_nar_type768=== RUN TestServerTLSConfig/missing_CA_file769=== PAUSE TestServerTLSConfig/missing_CA_file770=== CONT TestReadProxyDisabled771=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type772=== RUN TestServerTLSConfig/not_a_PEM_file773=== PAUSE TestServerTLSConfig/not_a_PEM_file774=== RUN TestIsValidUploadKey/nar_key,_narinfo_type775=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type776=== RUN TestIsValidUploadKey/listing_key,_narinfo_type777=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type778=== RUN TestIsValidUploadKey/traversal779=== PAUSE TestIsValidUploadKey/traversal780=== RUN TestIsValidUploadKey/traversal_nar781=== PAUSE TestIsValidUploadKey/traversal_nar782=== RUN TestIsValidUploadKey/absolute783=== PAUSE TestIsValidUploadKey/absolute784=== RUN TestIsValidUploadKey/empty_key785=== PAUSE TestIsValidUploadKey/empty_key786=== RUN TestIsValidUploadKey/unknown_type787=== PAUSE TestIsValidUploadKey/unknown_type788=== CONT TestReadRedirectUsesPublicS3URL789=== CONT TestReadProxyRangeRequest790=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure791=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure792=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart793=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart794=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts795=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts796=== CONT TestReadRedirectKeepsNarinfoProxied7972026-09-21 14:06:06.342 UTC [638] ERROR: relation "goose_db_version" does not exist at character 367982026-09-21 14:06:06.342 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-09-21 14:06:06.365 UTC [641] ERROR: relation "goose_db_version" does not exist at character 368002026-09-21 14:06:06.365 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026-09-21 14:06:06.370 UTC [642] ERROR: relation "goose_db_version" does not exist at character 368022026-09-21 14:06:06.370 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026-09-21 14:06:06.399 UTC [643] ERROR: relation "goose_db_version" does not exist at character 368042026-09-21 14:06:06.399 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026-09-21 14:06:06.403 UTC [644] ERROR: relation "goose_db_version" does not exist at character 368062026-09-21 14:06:06.403 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026/09/21 14:06:06 OK 20241026095416_initial_model.sql (32.01ms)8082026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)8092026/09/21 14:06:06 OK 20241026095416_initial_model.sql (36.22ms)8102026/09/21 14:06:06 OK 20251218171726_add_pins.sql (10.42ms)8112026/09/21 14:06:06 OK 20241026095416_initial_model.sql (38.5ms)8122026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (3.93ms)8132026/09/21 14:06:06 OK 20241026095416_initial_model.sql (22.3ms)8142026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (4.12ms)8152026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (7.85ms)8162026-09-21 14:06:06.443 UTC [647] ERROR: relation "goose_db_version" does not exist at character 368172026-09-21 14:06:06.443 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)8192026-09-21 14:06:06.446 UTC [648] ERROR: relation "goose_db_version" does not exist at character 368202026-09-21 14:06:06.446 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/09/21 14:06:06 OK 20241026095416_initial_model.sql (19.54ms)8222026/09/21 14:06:06 OK 20260905000000_add_claims.sql (5.15ms)8232026/09/21 14:06:06 OK 20251218171726_add_pins.sql (10.32ms)8242026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)8252026/09/21 14:06:06 OK 20251218171726_add_pins.sql (9.65ms)8262026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.84ms)8272026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000008282026/09/21 14:06:06 OK 20251218171726_add_pins.sql (7.74ms)8292026-09-21 14:06:06.453 UTC [649] ERROR: relation "goose_db_version" does not exist at character 368302026-09-21 14:06:06.453 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-09-21 14:06:06.462 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368322026-09-21 14:06:06.462 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-09-21 14:06:06.465 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368342026-09-21 14:06:06.465 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026/09/21 14:06:06 OK 1_commit_pending_closure.sql (14.97ms)8362026/09/21 14:06:06 OK 20251218171726_add_pins.sql (17.04ms)8372026-09-21 14:06:06.468 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368382026-09-21 14:06:06.468 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (18.54ms)8402026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (20.04ms)8412026/09/21 14:06:06 OK 20241026095416_initial_model.sql (19.42ms)8422026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (21.61ms)8432026/09/21 14:06:06 OK 2_object_stats_trigger.sql (4.52ms)8442026/09/21 14:06:06 goose: up to current file version: 28452026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)8462026/09/21 14:06:06 OK 20260905000000_add_claims.sql (6.07ms)8472026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (12.13ms)8482026/09/21 14:06:06 OK 20251218171726_add_pins.sql (6.53ms)8492026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.8ms)8502026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000008512026/09/21 14:06:06 OK 20260905000000_add_claims.sql (11.21ms)8522026/09/21 14:06:06 OK 20260905000000_add_claims.sql (11.07ms)8532026/09/21 14:06:06 OK 1_commit_pending_closure.sql (4.57ms)8542026/09/21 14:06:06 OK 20260905000000_add_claims.sql (7.12ms)8552026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (7.1ms)8562026/09/21 14:06:06 OK 2_object_stats_trigger.sql (3.05ms)8572026/09/21 14:06:06 goose: up to current file version: 28582026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (7.02ms)8592026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000008602026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (6.98ms)8612026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000008622026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (6.02ms)8632026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000008642026/09/21 14:06:06 OK 20260905000000_add_claims.sql (7.01ms)8652026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.91ms)8662026/09/21 14:06:06 OK 1_commit_pending_closure.sql (6.92ms)8672026/09/21 14:06:06 OK 1_commit_pending_closure.sql (6.59ms)8682026/09/21 14:06:06 OK 20241026095416_initial_model.sql (25ms)8692026-09-21 14:06:06.498 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368702026-09-21 14:06:06.498 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8712026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.8ms)8722026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000008732026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.81ms)8742026/09/21 14:06:06 goose: up to current file version: 28752026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)8762026/09/21 14:06:06 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"877--- PASS: TestService_AuthMiddleware (0.34s)878=== CONT TestReadRedirectNar8792026/09/21 14:06:06 OK 2_object_stats_trigger.sql (4.23ms)8802026/09/21 14:06:06 goose: up to current file version: 28812026/09/21 14:06:06 OK 2_object_stats_trigger.sql (4.33ms)8822026/09/21 14:06:06 goose: up to current file version: 28832026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.38ms)8842026/09/21 14:06:06 OK 20241026095416_initial_model.sql (30.07ms)8852026/09/21 14:06:06 OK 2_object_stats_trigger.sql (10.58ms)8862026/09/21 14:06:06 goose: up to current file version: 28872026/09/21 14:06:06 OK 20251218171726_add_pins.sql (17.87ms)8882026/09/21 14:06:06 OK 20241026095416_initial_model.sql (34.14ms)8892026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (15.17ms)8902026/09/21 14:06:06 OK 20241026095416_initial_model.sql (32.67ms)8912026/09/21 14:06:06 OK 20241026095416_initial_model.sql (37.32ms)8922026/09/21 14:06:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8932026/09/21 14:06:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"894--- PASS: TestService_NativeMTLS (0.36s)8952026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)896=== CONT TestGCBugBareHashReferences8972026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (5.21ms)8982026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (4.99ms)8992026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (7.3ms)9002026/09/21 14:06:06 OK 20251218171726_add_pins.sql (8.62ms)9012026/09/21 14:06:06 OK 20251218171726_add_pins.sql (6.3ms)9022026-09-21 14:06:06.530 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369032026-09-21 14:06:06.530 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9042026/09/21 14:06:06 OK 20251218171726_add_pins.sql (6.88ms)9052026-09-21 14:06:06.531 UTC [657] ERROR: relation "goose_db_version" does not exist at character 369062026-09-21 14:06:06.531 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026-09-21 14:06:06.532 UTC [661] ERROR: relation "goose_db_version" does not exist at character 369082026-09-21 14:06:06.532 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026-09-21 14:06:06.532 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369102026-09-21 14:06:06.532 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9112026/09/21 14:06:06 OK 20260905000000_add_claims.sql (6.5ms)9122026/09/21 14:06:06 OK 20251218171726_add_pins.sql (8.58ms)9132026/09/21 14:06:06 OK 20241026095416_initial_model.sql (13.65ms)9142026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (6.63ms)9152026-09-21 14:06:06.536 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369162026-09-21 14:06:06.536 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)9182026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (8.41ms)9192026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)9202026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (4.47ms)9212026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000009222026/09/21 14:06:06 OK 20251218171726_add_pins.sql (3.81ms)9232026-09-21 14:06:06.540 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369242026-09-21 14:06:06.540 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026/09/21 14:06:06 OK 1_commit_pending_closure.sql (4.08ms)9262026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (8.57ms)9272026/09/21 14:06:06 OK 20260905000000_add_claims.sql (5.68ms)9282026/09/21 14:06:06 OK 20260905000000_add_claims.sql (6.79ms)9292026/09/21 14:06:06 OK 20260905000000_add_claims.sql (6.57ms)9302026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.92ms)9312026/09/21 14:06:06 goose: up to current file version: 29322026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)9332026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.53ms)9342026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000009352026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.87ms)9362026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000009372026/09/21 14:06:06 OK 20260905000000_add_claims.sql (5.54ms)9382026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (4.19ms)9392026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000009402026-09-21 14:06:06.548 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369412026-09-21 14:06:06.548 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9422026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures9432026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.25ms)9442026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.88ms)9452026/09/21 14:06:06 OK 20241026095416_initial_model.sql (11.77ms)9462026-09-21 14:06:06.550 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369472026-09-21 14:06:06.550 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9482026-09-21 14:06:06.551 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369492026-09-21 14:06:06.551 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9502026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (4.44ms)9512026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000009522026/09/21 14:06:06 OK 1_commit_pending_closure.sql (4.79ms)9532026/09/21 14:06:06 OK 1_commit_pending_closure.sql (5.08ms)9542026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.84ms)9552026/09/21 14:06:06 goose: successfully migrated database to version: 202609200000009562026-09-21 14:06:06.553 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369572026-09-21 14:06:06.553 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.78ms)9592026/09/21 14:06:06 goose: up to current file version: 29602026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)9612026/09/21 14:06:06 OK 20241026095416_initial_model.sql (12.22ms)9622026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.57ms)9632026/09/21 14:06:06 goose: up to current file version: 29642026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.62ms)9652026/09/21 14:06:06 goose: up to current file version: 29662026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.84ms)9672026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.78ms)9682026/09/21 14:06:06 OK 20241026095416_initial_model.sql (12.99ms)9692026/09/21 14:06:06 OK 20241026095416_initial_model.sql (13.02ms)9702026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.16ms)9712026/09/21 14:06:06 goose: up to current file version: 29722026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.32ms)9732026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)9742026/09/21 14:06:06 goose: up to current file version: 29752026/09/21 14:06:06 OK 20251218171726_add_pins.sql (5.16ms)9762026/09/21 14:06:06 OK 20241026095416_initial_model.sql (11.97ms)9772026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)9782026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)9792026-09-21 14:06:06.560 UTC [669] ERROR: relation "goose_db_version" does not exist at character 369802026-09-21 14:06:06.560 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9812026/09/21 14:06:06 OK 20241026095416_initial_model.sql (13.43ms)9822026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)9832026-09-21 14:06:06.561 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369842026-09-21 14:06:06.561 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9852026/09/21 14:06:06 OK 20251218171726_add_pins.sql (4.14ms)986--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)987=== CONT TestReadProxyNarStreaming9882026/09/21 14:06:06 OK 20251218171726_add_pins.sql (4.32ms)9892026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)9902026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)9912026/09/21 14:06:06 OK 20251218171726_add_pins.sql (4.11ms)9922026/09/21 14:06:06 OK 20251218171726_add_pins.sql (3.71ms)9932026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (5.37ms)9942026/09/21 14:06:06 OK 20251218171726_add_pins.sql (4.47ms)9952026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.55ms)9962026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)9972026/09/21 14:06:06 OK 20241026095416_initial_model.sql (10.54ms)9982026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)9992026/09/21 14:06:06 OK 20241026095416_initial_model.sql (12.04ms)10002026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)10012026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)10022026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.46ms)10032026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010042026/09/21 14:06:06 OK 20241026095416_initial_model.sql (11.76ms)10052026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)10062026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.18ms)10072026/09/21 14:06:06 OK 20260905000000_add_claims.sql (3.99ms)10082026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.59ms)10092026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)10102026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.27ms)10112026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)10122026/09/21 14:06:06 OK 20241026095416_initial_model.sql (11.5ms)10132026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.15ms)10142026/09/21 14:06:06 OK 20251218171726_add_pins.sql (4.12ms)10152026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.51ms)10162026/09/21 14:06:06 goose: up to current file version: 210172026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.73ms)10182026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010192026/09/21 14:06:06 OK 20251218171726_add_pins.sql (3.73ms)10202026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.63ms)10212026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010222026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)10232026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3ms)10242026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010252026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.45ms)10262026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010272026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.54ms)10282026/09/21 14:06:06 OK 20251218171726_add_pins.sql (4.68ms)10292026/09/21 14:06:06 OK 20241026095416_initial_model.sql (10.79ms)10302026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.85ms)10312026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.12ms)10322026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)10332026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.54ms)10342026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.85ms)10352026/09/21 14:06:06 goose: up to current file version: 210362026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.94ms)10372026/09/21 14:06:06 goose: up to current file version: 210382026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)10392026/09/21 14:06:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10402026/09/21 14:06:06 OK 20251218171726_add_pins.sql (4.2ms)10412026/09/21 14:06:06 OK 20241026095416_initial_model.sql (11.84ms)10422026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)10432026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.74ms)10442026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010452026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.5ms)10462026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.02ms)10472026/09/21 14:06:06 goose: up to current file version: 210482026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)10492026/09/21 14:06:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1050--- PASS: TestCompleteMultipartUnregistered (0.43s)10512026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.31ms)1052=== CONT TestMetricsInventory10532026/09/21 14:06:06 goose: up to current file version: 210542026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)10552026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.4ms)10562026/09/21 14:06:06 OK 1_commit_pending_closure.sql (10.36ms)10572026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (10.72ms)10582026/09/21 14:06:06 OK 20260905000000_add_claims.sql (10.9ms)10592026/09/21 14:06:06 OK 20251218171726_add_pins.sql (10.48ms)10602026/09/21 14:06:06 OK 20251218171726_add_pins.sql (10.78ms)10612026/09/21 14:06:06 OK 20260905000000_add_claims.sql (12.02ms)10622026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (11.42ms)10632026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010642026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)10652026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.49ms)10662026/09/21 14:06:06 OK 2_object_stats_trigger.sql (4.52ms)10672026/09/21 14:06:06 goose: up to current file version: 210682026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (5.06ms)10692026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010702026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.5ms)10712026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010722026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.85ms)10732026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.89ms)10742026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010752026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)10762026/09/21 14:06:06 OK 20260905000000_add_claims.sql (3.21ms)10772026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.41ms)10782026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.6ms)10792026/09/21 14:06:06 goose: up to current file version: 210802026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3ms)10812026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.86ms)10822026/09/21 14:06:06 goose: up to current file version: 210832026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.14ms)10842026/09/21 14:06:06 OK 20260905000000_add_claims.sql (3.02ms)10852026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.59ms)10862026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010872026/09/21 14:06:06 OK 2_object_stats_trigger.sql (2.19ms)10882026/09/21 14:06:06 goose: up to current file version: 210892026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.81ms)10902026/09/21 14:06:06 goose: up to current file version: 210912026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.39ms)10922026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000010932026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.41ms)10942026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures10952026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.8ms)10962026/09/21 14:06:06 goose: up to current file version: 210972026/09/21 14:06:06 OK 1_commit_pending_closure.sql (3.59ms)10982026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.85ms)10992026/09/21 14:06:06 goose: up to current file version: 211002026-09-21 14:06:06.614 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3611012026-09-21 14:06:06.614 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11022026-09-21 14:06:06.627 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3611032026-09-21 14:06:06.627 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026/09/21 14:06:06 OK 20241026095416_initial_model.sql (8.3ms)11052026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)11062026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures11072026/09/21 14:06:06 OK 20251218171726_add_pins.sql (3.74ms)11082026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)11092026/09/21 14:06:06 OK 20260905000000_add_claims.sql (3.19ms)11102026/09/21 14:06:06 OK 20241026095416_initial_model.sql (7.55ms)11112026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.36ms)11122026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000011132026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)11142026/09/21 14:06:06 OK 1_commit_pending_closure.sql (1.77ms)11152026/09/21 14:06:06 OK 20251218171726_add_pins.sql (2.41ms)11162026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.22ms)11172026/09/21 14:06:06 goose: up to current file version: 211182026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures11192026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)11202026-09-21 14:06:06.651 UTC [678] ERROR: relation "goose_db_version" does not exist at character 3611212026-09-21 14:06:06.651 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/09/21 14:06:06 OK 20260905000000_add_claims.sql (2.56ms)11232026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.37ms)11242026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000011252026/09/21 14:06:06 OK 1_commit_pending_closure.sql (1.24ms)11262026/09/21 14:06:06 OK 2_object_stats_trigger.sql (745.09µs)11272026/09/21 14:06:06 goose: up to current file version: 211282026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures11292026/09/21 14:06:06 OK 20241026095416_initial_model.sql (7.39ms)11302026-09-21 14:06:06.665 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3611312026-09-21 14:06:06.665 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)11332026/09/21 14:06:06 OK 20251218171726_add_pins.sql (2.23ms)11342026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (2.49ms)11352026/09/21 14:06:06 OK 20260905000000_add_claims.sql (2.71ms)11362026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.88ms)11372026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000011382026/09/21 14:06:06 OK 20241026095416_initial_model.sql (7.11ms)11392026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.11ms)11402026/09/21 14:06:06 OK 2_object_stats_trigger.sql (806.72µs)11412026/09/21 14:06:06 goose: up to current file version: 211422026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures11432026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)11442026/09/21 14:06:06 OK 20251218171726_add_pins.sql (2.07ms)11452026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (2.3ms)11462026/09/21 14:06:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11472026/09/21 14:06:06 OK 20260905000000_add_claims.sql (2.66ms)11482026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (1.48ms)11492026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000011502026/09/21 14:06:06 OK 1_commit_pending_closure.sql (1.35ms)11512026/09/21 14:06:06 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTEyZWZkNDctMzA4Yy00YjA4LThjMzctYmE5YzZhMDQ3OWQxLjUwMDZjYzQ2LTZiY2UtNDJhMy04Y2NiLThmODJkZTc4ZmMzN3gxNzg5OTk5NTY2NjY4MDIwNjIw11522026/09/21 14:06:06 OK 2_object_stats_trigger.sql (729.9µs)11532026/09/21 14:06:06 goose: up to current file version: 211542026/09/21 14:06:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTEyZWZkNDctMzA4Yy00YjA4LThjMzctYmE5YzZhMDQ3OWQxLjUwMDZjYzQ2LTZiY2UtNDJhMy04Y2NiLThmODJkZTc4ZmMzN3gxNzg5OTk5NTY2NjY4MDIwNjIw parts=11155--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.54s)1156=== CONT TestReadProxyRootRedirectsToIndexHTML1157--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.55s)1158=== CONT TestReadProxyConditionalGet1159--- PASS: TestReadProxyNarinfo (0.58s)1160=== CONT TestReadProxyHead11612026/09/21 14:06:06 INFO Received cleanup request method=DELETE path=/api/pending_closures11622026/09/21 14:06:06 INFO Aborted multipart uploads count=011632026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/21 14:06:06 INFO Received cleanup request method=DELETE path=/api/pending_closures11652026/09/21 14:06:06 INFO Aborted multipart uploads count=11166--- PASS: TestService_Rustfstest (0.62s)1167=== CONT TestNARDeduplicationMetadataUploadBug11682026/09/21 14:06:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11692026-09-21 14:06:06.791 UTC [653] ERROR: Closure does not exist: id=111702026-09-21 14:06:06.791 UTC [653] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11712026-09-21 14:06:06.791 UTC [653] STATEMENT: -- name: CommitPendingClosure :exec1172 SELECT commit_pending_closure($1::bigint)1173 11742026-09-21 14:06:06.791 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3611752026-09-21 14:06:06.791 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11762026/09/21 14:06:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1177--- PASS: TestService_cleanupPendingClosuresHandler (0.63s)1178=== CONT TestReadProxyInvalidPath11792026-09-21 14:06:06.804 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3611802026-09-21 14:06:06.804 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11812026/09/21 14:06:06 OK 20241026095416_initial_model.sql (8.69ms)11822026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)11832026/09/21 14:06:06 OK 20251218171726_add_pins.sql (2.88ms)11842026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)11852026/09/21 14:06:06 OK 20260905000000_add_claims.sql (3.31ms)11862026/09/21 14:06:06 OK 20241026095416_initial_model.sql (9.75ms)11872026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (3.32ms)11882026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000011892026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)11902026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.8ms)11912026/09/21 14:06:06 OK 20251218171726_add_pins.sql (2.75ms)11922026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.7ms)11932026/09/21 14:06:06 goose: up to current file version: 211942026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)11952026-09-21 14:06:06.829 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3611962026-09-21 14:06:06.829 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11972026/09/21 14:06:06 OK 20260905000000_add_claims.sql (2.94ms)11982026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.12ms)11992026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000012002026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.05ms)12012026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.55ms)12022026/09/21 14:06:06 goose: up to current file version: 212032026/09/21 14:06:06 OK 20241026095416_initial_model.sql (8.85ms)12042026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures12052026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures12062026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)12072026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures12082026/09/21 14:06:06 OK 20251218171726_add_pins.sql (3.08ms)12092026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)12102026/09/21 14:06:06 OK 20260905000000_add_claims.sql (14.31ms)12112026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.69ms)12122026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000012132026/09/21 14:06:06 OK 1_commit_pending_closure.sql (1.82ms)12142026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.23ms)12152026/09/21 14:06:06 goose: up to current file version: 212162026-09-21 14:06:06.875 UTC [695] ERROR: relation "goose_db_version" does not exist at character 3612172026-09-21 14:06:06.875 UTC [695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1218--- PASS: TestResurrectedObjectNotDeleted (0.62s)1219=== CONT TestCreatePendingClosureRejectsOversizedNAR12202026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures1221--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1222=== CONT TestReadProxy40412232026-09-21 14:06:06.885 UTC [697] ERROR: relation "goose_db_version" does not exist at character 3612242026-09-21 14:06:06.885 UTC [697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12252026/09/21 14:06:06 OK 20241026095416_initial_model.sql (6.94ms)12262026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)12272026/09/21 14:06:06 OK 20251218171726_add_pins.sql (2.7ms)12282026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)12292026/09/21 14:06:06 OK 20260905000000_add_claims.sql (4.63ms)12302026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures12312026/09/21 14:06:06 OK 20241026095416_initial_model.sql (10.13ms)12322026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (1.56ms)12332026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000012342026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)12352026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.65ms)12362026/09/21 14:06:06 OK 20251218171726_add_pins.sql (3.74ms)12372026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.7ms)12382026/09/21 14:06:06 goose: up to current file version: 212392026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)12402026/09/21 14:06:06 OK 20260905000000_add_claims.sql (2.32ms)12412026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.71ms)12422026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000012432026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.19ms)12442026/09/21 14:06:06 OK 2_object_stats_trigger.sql (950.3µs)12452026/09/21 14:06:06 goose: up to current file version: 212462026/09/21 14:06:06 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12472026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures1248--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.76s)1249=== CONT TestCacheConfigHandlerMaxNarSize1250--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1251=== CONT TestGenerateLandingPage12522026/09/21 14:06:06 INFO Received uploads request method=POST path=/api/pending_closures1253--- PASS: TestGenerateLandingPage (0.01s)1254=== CONT TestClientErrorHandling1255=== RUN TestClientErrorHandling/InvalidStorePath1256=== PAUSE TestClientErrorHandling/InvalidStorePath1257=== RUN TestClientErrorHandling/InvalidAuthToken1258=== PAUSE TestClientErrorHandling/InvalidAuthToken1259=== RUN TestClientErrorHandling/ServerNotAvailable1260=== PAUSE TestClientErrorHandling/ServerNotAvailable1261=== CONT TestService_readinessHandler12622026-09-21 14:06:06.953 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3612632026-09-21 14:06:06.953 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12642026/09/21 14:06:06 OK 20241026095416_initial_model.sql (7.47ms)12652026/09/21 14:06:06 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)12662026/09/21 14:06:06 OK 20251218171726_add_pins.sql (2.27ms)12672026/09/21 14:06:06 OK 20260628120000_add_object_size_and_stats.sql (3.11ms)1268--- PASS: TestReadRedirectUsesPublicS3URL (0.71s)1269=== CONT TestService_healthCheckHandler12702026/09/21 14:06:06 OK 20260905000000_add_claims.sql (2.87ms)12712026/09/21 14:06:06 OK 20260920000000_drop_claims.sql (2.16ms)12722026/09/21 14:06:06 goose: successfully migrated database to version: 2026092000000012732026/09/21 14:06:06 OK 1_commit_pending_closure.sql (2.06ms)12742026/09/21 14:06:06 OK 2_object_stats_trigger.sql (1.27ms)12752026/09/21 14:06:06 goose: up to current file version: 21276--- PASS: TestReadRedirectKeepsNarinfoProxied (0.66s)1277=== CONT TestLeadEndsOnShutdown12782026-09-21 14:06:07.009 UTC [707] ERROR: relation "goose_db_version" does not exist at character 3612792026-09-21 14:06:07.009 UTC [707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12802026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures12812026/09/21 14:06:07 OK 20241026095416_initial_model.sql (18.89ms)12822026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (3.8ms)12832026/09/21 14:06:07 OK 20251218171726_add_pins.sql (6.03ms)12842026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)12852026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.73ms)12862026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.77ms)12872026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000012882026-09-21 14:06:07.057 UTC [708] ERROR: relation "goose_db_version" does not exist at character 3612892026-09-21 14:06:07.057 UTC [708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.67ms)12912026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.3ms)12922026/09/21 14:06:07 goose: up to current file version: 21293--- PASS: TestObjectStatsTrigger (0.81s)1294=== CONT TestGracefulShutdownDrainsInflight12952026/09/21 14:06:07 INFO Starting HTTP server address=127.0.0.1:4113912962026/09/21 14:06:07 INFO Shutdown signal received, draining in-flight requests timeout=10s12972026/09/21 14:06:07 OK 20241026095416_initial_model.sql (6.8ms)12982026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (883.52µs)12992026/09/21 14:06:07 OK 20251218171726_add_pins.sql (1.94ms)13002026-09-21 14:06:07.073 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3613012026-09-21 14:06:07.073 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13022026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (2.2ms)13032026/09/21 14:06:07 OK 20260905000000_add_claims.sql (3.05ms)13042026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (1.56ms)13052026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000013062026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.25ms)13072026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.12ms)13082026/09/21 14:06:07 goose: up to current file version: 213092026/09/21 14:06:07 OK 20241026095416_initial_model.sql (7.24ms)13102026/09/21 14:06:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13112026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)13122026/09/21 14:06:07 OK 20251218171726_add_pins.sql (2.02ms)13132026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (2.81ms)13142026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.22ms)13152026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (1.55ms)13162026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000013172026/09/21 14:06:07 OK 1_commit_pending_closure.sql (1.33ms)13182026/09/21 14:06:07 OK 2_object_stats_trigger.sql (795.6µs)13192026/09/21 14:06:07 goose: up to current file version: 21320--- PASS: TestReadProxyDisabled (0.84s)13212026/09/21 14:06:07 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTEyZWZkNDctMzA4Yy00YjA4LThjMzctYmE5YzZhMDQ3OWQxLmVlOTAyNTUxLTQwYjctNGE0MS05YjQ0LWY4NGNkMmJiZmE2MngxNzg5OTk5NTY2NjE4NzA1OTg5 parts=101322=== CONT TestLeadElectsOneAndHandsOver13232026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13242026/09/21 14:06:07 INFO Completed upload id=113252026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures13262026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/21 14:06:07 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13282026/09/21 14:06:07 WARN Found objects in DB but missing from S3, will re-upload count=11329--- PASS: TestService_verifyS3Integrity (0.95s)1330=== CONT TestGCTaskStore_Fail1331--- PASS: TestGCTaskStore_Fail (0.00s)1332=== CONT TestResolveDBConnectionString1333=== RUN TestResolveDBConnectionString/flag_wins1334=== PAUSE TestResolveDBConnectionString/flag_wins1335=== RUN TestResolveDBConnectionString/file_when_flag_empty1336=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1337=== RUN TestResolveDBConnectionString/missing_file_is_an_error1338=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1339=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1340=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1341=== RUN TestResolveDBConnectionString/nothing_configured1342=== PAUSE TestResolveDBConnectionString/nothing_configured1343=== CONT TestPinProtectsFromGC1344--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1345=== CONT TestGCTaskStore_PhaseUpdates1346--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1347=== CONT TestClientSharedPathCommittedMidPush1348--- PASS: TestReadProxyRangeRequest (0.87s)1349=== CONT TestClientWithDependencies13502026/09/21 14:06:07 INFO Received cleanup request method=DELETE path=/api/pending_closures13512026/09/21 14:06:07 INFO Aborted multipart uploads count=11352--- PASS: TestMultipartCleanup (0.89s)1353=== CONT TestGCTaskStore_CompletedAllowsNewTask1354--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1355=== CONT TestClientMultipleUploads1356--- PASS: TestReadRedirectNar (0.67s)1357=== CONT TestClientIntegration13582026-09-21 14:06:07.183 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3613592026-09-21 14:06:07.183 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13602026-09-21 14:06:07.206 UTC [740] ERROR: relation "goose_db_version" does not exist at character 3613612026-09-21 14:06:07.206 UTC [740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13622026/09/21 14:06:07 OK 20241026095416_initial_model.sql (10.36ms)13632026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)13642026/09/21 14:06:07 OK 20251218171726_add_pins.sql (4.14ms)13652026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)13662026/09/21 14:06:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13672026/09/21 14:06:07 OK 20241026095416_initial_model.sql (9.94ms)13682026/09/21 14:06:07 OK 20260905000000_add_claims.sql (4.57ms)13692026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)13702026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (3.22ms)13712026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000013722026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.89ms)13732026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.39ms)13742026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.19ms)13752026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)13762026/09/21 14:06:07 goose: up to current file version: 213772026-09-21 14:06:07.235 UTC [741] ERROR: relation "goose_db_version" does not exist at character 3613782026-09-21 14:06:07.235 UTC [741] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13792026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.83ms)13802026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.31ms)13812026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000013822026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.95ms)1383--- PASS: TestReadProxyNarStreaming (0.68s)1384=== CONT TestGCTaskStore_GetReturnsLatest1385--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1386=== CONT TestGCTaskStore_StartNew1387--- PASS: TestGCTaskStore_StartNew (0.00s)13882026-09-21 14:06:07.242 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3613892026-09-21 14:06:07.242 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1390=== CONT TestGCTaskStore_DeduplicateSameParams1391--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1392=== CONT TestGCMetrics13932026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.49ms)13942026/09/21 14:06:07 goose: up to current file version: 213952026-09-21 14:06:07.245 UTC [743] ERROR: relation "goose_db_version" does not exist at character 3613962026-09-21 14:06:07.245 UTC [743] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13972026/09/21 14:06:07 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTEyZWZkNDctMzA4Yy00YjA4LThjMzctYmE5YzZhMDQ3OWQxLmU1NmZlYzg1LTBkOWQtNGZjOC04ZGJmLWEwMzhiNWQ0NDE3ZXgxNzg5OTk5NTY2NjQzMzk5MTY0 parts=1213982026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.96ms)1399--- PASS: TestRedundantMultipartUpload (1.09s)1400=== CONT TestGCTaskStore_GetEmpty1401--- PASS: TestGCTaskStore_GetEmpty (0.00s)1402=== CONT TestGCTaskStore_ConflictDifferentParams1403--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1404=== CONT TestService_RequireScope_OIDC14052026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)14062026/09/21 14:06:07 OK 20251218171726_add_pins.sql (2.82ms)14072026/09/21 14:06:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40559/oidc14082026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.17ms)14092026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)14102026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)14112026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.8ms)14122026/09/21 14:06:07 OK 20251218171726_add_pins.sql (4.03ms)14132026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)14142026/09/21 14:06:07 OK 20260905000000_add_claims.sql (4.18ms)14152026/09/21 14:06:07 OK 20251218171726_add_pins.sql (2.92ms)14162026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)14172026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.76ms)14182026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000014192026-09-21 14:06:07.276 UTC [748] ERROR: relation "goose_db_version" does not exist at character 3614202026-09-21 14:06:07.276 UTC [748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14212026/09/21 14:06:07 OK 1_commit_pending_closure.sql (11.57ms)14222026/09/21 14:06:07 OK 20260905000000_add_claims.sql (16.76ms)14232026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (16.94ms)14242026/09/21 14:06:07 OK 2_object_stats_trigger.sql (9.95ms)14252026/09/21 14:06:07 goose: up to current file version: 214262026/09/21 14:06:07 OK 20260905000000_add_claims.sql (6.71ms)14272026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (7.54ms)14282026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000014292026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (3.03ms)14302026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000014312026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.44ms)14322026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.44ms)14332026/09/21 14:06:07 goose: up to current file version: 214342026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.44ms)14352026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.42ms)14362026/09/21 14:06:07 goose: up to current file version: 214372026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.89ms)14382026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)14392026/09/21 14:06:07 OK 20251218171726_add_pins.sql (1.91ms)1440--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.60s)1441=== CONT TestService_ReadAuthMiddleware14422026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (2.88ms)14432026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.78ms)1444--- PASS: TestMetricsInventory (0.73s)1445=== CONT TestClientCADerivations14462026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.51ms)14472026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000014482026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.4ms)14492026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.73ms)14502026/09/21 14:06:07 goose: up to current file version: 214512026-09-21 14:06:07.333 UTC [753] ERROR: relation "goose_db_version" does not exist at character 3614522026-09-21 14:06:07.333 UTC [753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1453--- PASS: TestReadProxyConditionalGet (0.62s)1454=== CONT TestCacheStatsHandler14552026/09/21 14:06:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14562026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.72ms)14572026-09-21 14:06:07.350 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3614582026-09-21 14:06:07.350 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14592026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)14602026/09/21 14:06:07 OK 20251218171726_add_pins.sql (2.9ms)14612026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)14622026/09/21 14:06:07 OK 20260905000000_add_claims.sql (4.15ms)14632026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.56ms)14642026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000014652026/09/21 14:06:07 OK 20241026095416_initial_model.sql (9.51ms)14662026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.63ms)14672026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)14682026/09/21 14:06:07 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTEyZWZkNDctMzA4Yy00YjA4LThjMzctYmE5YzZhMDQ3OWQxLjIyNmQxOGZkLWRiZjYtNDVkZC04MTEwLTM1YjM5MmUzNDY0MXgxNzg5OTk5NTY2ODY1ODEwNjIw parts=1014692026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14702026/09/21 14:06:07 OK 2_object_stats_trigger.sql (3.15ms)14712026/09/21 14:06:07 goose: up to current file version: 21472--- PASS: TestReadProxyHead (0.63s)1473=== CONT TestService_AuthMiddleware_OIDC14742026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.75ms)14752026/09/21 14:06:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40843/oidc14762026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)14772026/09/21 14:06:07 INFO Completed upload id=114782026/09/21 14:06:07 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014792026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures14802026/09/21 14:06:07 OK 20260905000000_add_claims.sql (9.94ms)14812026/09/21 14:06:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures14822026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (4.44ms)14832026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000014842026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.29ms)14852026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.34ms)14862026/09/21 14:06:07 goose: up to current file version: 214872026/09/21 14:06:07 INFO Aborted multipart uploads count=01488=== NAME TestOrphanedObjectsGC1489 orphaned_objects_gc_test.go:290: GC Test Summary:1490 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1491 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1492 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1493 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1494 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1495--- PASS: TestOrphanedObjectsGC (1.15s)1496=== CONT TestCacheConfigHandler1497=== RUN TestCacheConfigHandler/full_config,_no_issuer1498=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1499=== RUN TestCacheConfigHandler/no_cache_url_configured1500=== PAUSE TestCacheConfigHandler/no_cache_url_configured1501=== RUN TestCacheConfigHandler/no_signing_keys1502=== PAUSE TestCacheConfigHandler/no_signing_keys1503=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1504=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1505=== CONT TestService_ReadScope_PublicByDefault15062026-09-21 14:06:07.409 UTC [769] ERROR: relation "goose_db_version" does not exist at character 3615072026-09-21 14:06:07.409 UTC [769] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15082026/09/21 14:06:07 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=015092026-09-21 14:06:07.411 UTC [770] ERROR: relation "goose_db_version" does not exist at character 3615102026-09-21 14:06:07.411 UTC [770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15112026/09/21 14:06:07 INFO Vacuumed table table=pending_closures15122026/09/21 14:06:07 INFO Vacuumed table table=pending_objects15132026/09/21 14:06:07 INFO Vacuumed table table=multipart_uploads15142026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.46ms)15152026/09/21 14:06:07 INFO Vacuumed table table=closures15162026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.54ms)15172026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)15182026/09/21 14:06:07 INFO Vacuumed table table=objects15192026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)15202026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.05ms)1521--- PASS: TestReadProxyInvalidPath (0.64s)1522=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15232026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.03ms)15242026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)15252026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)15262026/09/21 14:06:07 OK 20260905000000_add_claims.sql (3.93ms)15272026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.8ms)15282026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000015292026/09/21 14:06:07 OK 20260905000000_add_claims.sql (4.22ms)15302026/09/21 14:06:07 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001531--- PASS: TestService_createPendingClosureHandler (1.28s)1532=== NAME TestNARDeduplicationMetadataUploadBug1533 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3458144232/001/store/5g3zs2cdzvpiw0rr9pk5nbns2ajiy0ik-file1.txt1534=== CONT TestService_AuthMiddleware_MTLSProxyHeader1535--- PASS: TestGCBugBareHashReferences (0.92s)1536=== CONT TestProxyWriteTimeout/narinfo1537=== CONT TestProxyWriteTimeout/unknown_size1538=== CONT TestProxyWriteTimeout/1_GiB_nar1539=== CONT TestProxyWriteTimeout/10_GiB_nar1540--- PASS: TestProxyWriteTimeout (0.10s)1541 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1542 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1543 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1544 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1545=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15462026/09/21 14:06:07 INFO Received uploads request method=POST path=/1547=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15482026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (3.07ms)15492026/09/21 14:06:07 OK 1_commit_pending_closure.sql (3.44ms)15502026-09-21 14:06:07.444 UTC [791] ERROR: relation "goose_db_version" does not exist at character 3615512026-09-21 14:06:07.444 UTC [791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15522026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000015532026/09/21 14:06:07 INFO Received request for more parts method=POST path=/1554=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15552026/09/21 14:06:07 INFO Received complete multipart upload request method=POST path=/1556=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15572026/09/21 14:06:07 INFO Received uploads request method=POST path=/1558--- PASS: TestUploadHandlersRejectInvalidKeys (0.10s)1559 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1560 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1561 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1562 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1563=== CONT TestParseSingleRange/none1564=== CONT TestParseSingleRange/start_far_past_EOF1565=== CONT TestParseSingleRange/start_past_EOF1566=== CONT TestParseSingleRange/single_byte1567=== CONT TestParseSingleRange/suffix_exceeds_size1568=== CONT TestParseSingleRange/malformed_both_empty1569=== CONT TestParseSingleRange/malformed_no_dash1570=== CONT TestParseSingleRange/multi-range_ignored1571=== CONT TestParseSingleRange/unknown_unit1572=== CONT TestParseSingleRange/end_clamped_to_size1573=== CONT TestParseSingleRange/malformed_end_before_start15742026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.53ms)1575=== CONT TestParseSingleRange/suffix15762026/09/21 14:06:07 goose: up to current file version: 21577=== CONT TestParseSingleRange/open-ended1578=== CONT TestParseSingleRange/closed1579--- PASS: TestParseSingleRange (0.01s)1580 --- PASS: TestParseSingleRange/none (0.00s)1581 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1582 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1583 --- PASS: TestParseSingleRange/single_byte (0.00s)1584 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1585 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1586 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1587 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1588 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1589 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1590 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1591 --- PASS: TestParseSingleRange/suffix (0.00s)1592 --- PASS: TestParseSingleRange/open-ended (0.00s)1593 --- PASS: TestParseSingleRange/closed (0.00s)1594=== CONT TestIsValidCachePath/narinfo1595=== CONT TestIsValidCachePath/index.html1596=== CONT TestIsValidCachePath/nix-cache-info1597=== CONT TestIsValidCachePath/realisation1598=== CONT TestIsValidCachePath/log1599=== CONT TestIsValidCachePath/ls1600=== CONT TestIsValidCachePath/traversal_parent1601=== CONT TestIsValidCachePath/nar_uncompressed1602=== CONT TestIsValidCachePath/nar_bz21603=== CONT TestIsValidCachePath/nar_xz1604=== CONT TestIsValidCachePath/short_hash1605=== CONT TestIsValidCachePath/nar_zst1606=== CONT TestIsValidCachePath/wrong_extension1607=== CONT TestIsValidCachePath/leading_slash1608=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars16092026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.31ms)1610=== CONT TestIsValidCachePath/empty1611=== CONT TestIsValidCachePath/random_path1612=== CONT TestIsValidCachePath/invalid_char_e1613=== CONT TestIsValidCachePath/traversal_in_middle1614=== CONT TestIsValidCachePath/invalid_char_u1615--- PASS: TestIsValidCachePath (0.10s)1616 --- PASS: TestIsValidCachePath/narinfo (0.00s)1617 --- PASS: TestIsValidCachePath/index.html (0.00s)1618 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1619 --- PASS: TestIsValidCachePath/realisation (0.00s)1620 --- PASS: TestIsValidCachePath/log (0.00s)1621 --- PASS: TestIsValidCachePath/ls (0.00s)1622 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1623 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1624 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1625 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1626 --- PASS: TestIsValidCachePath/short_hash (0.00s)1627 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1628 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1629 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1630 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1631 --- PASS: TestIsValidCachePath/empty (0.00s)1632 --- PASS: TestIsValidCachePath/random_path (0.00s)1633 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1634 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1635 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1636=== CONT TestServerTLSConfig/no_client_CA1637=== CONT TestServerTLSConfig/not_a_PEM_file1638=== CONT TestServerTLSConfig/missing_CA_file1639--- PASS: TestServerTLSConfig (0.00s)1640 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1641 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1642 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1643=== CONT TestIsValidUploadKey/narinfo1644=== CONT TestIsValidUploadKey/unknown_type1645=== CONT TestIsValidUploadKey/empty_key1646=== CONT TestIsValidUploadKey/absolute1647=== CONT TestIsValidUploadKey/traversal_nar1648=== CONT TestIsValidUploadKey/traversal1649=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1650=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1651=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1652=== CONT TestIsValidUploadKey/index.html1653=== CONT TestIsValidUploadKey/build_log_home-manager_file1654=== CONT TestIsValidUploadKey/build_log1655=== CONT TestIsValidUploadKey/listing1656=== CONT TestIsValidUploadKey/nar_plain1657=== CONT TestIsValidUploadKey/nar_xz1658=== CONT TestIsValidUploadKey/build_log_plus_in_name1659=== CONT TestIsValidUploadKey/nar_zst1660=== CONT TestIsValidUploadKey/nix-cache-info1661=== CONT TestIsValidUploadKey/realisation1662=== CONT TestIsValidUploadKey/build_log_equals1663=== CONT TestIsValidUploadKey/realisation_plus_in_output1664=== CONT TestIsValidUploadKey/build_log_question_mark1665--- PASS: TestIsValidUploadKey (0.10s)1666 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1667 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1668 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1669 --- PASS: TestIsValidUploadKey/absolute (0.00s)1670 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1671 --- PASS: TestIsValidUploadKey/traversal (0.00s)1672 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1673 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1674 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1675 --- PASS: TestIsValidUploadKey/index.html (0.00s)1676 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1677 --- PASS: TestIsValidUploadKey/build_log (0.00s)1678 --- PASS: TestIsValidUploadKey/listing (0.00s)1679 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1680 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1681 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1682 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1683 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1684 --- PASS: TestIsValidUploadKey/realisation (0.00s)1685 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1686 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1687 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1688=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16892026/09/21 14:06:07 INFO Received uploads request method=POST path=/16902026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.99ms)16912026/09/21 14:06:07 goose: up to current file version: 21692--- PASS: TestReadProxy404 (0.58s)1693=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16942026/09/21 14:06:07 INFO Received request for more parts method=POST path=/16952026/09/21 14:06:07 OK 20241026095416_initial_model.sql (9.98ms)16962026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)16972026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.08ms)16982026/09/21 14:06:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16992026-09-21 14:06:07.471 UTC [795] ERROR: relation "goose_db_version" does not exist at character 3617002026-09-21 14:06:07.471 UTC [795] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17012026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (11.13ms)17022026/09/21 14:06:07 OK 20260905000000_add_claims.sql (3.97ms)17032026/09/21 14:06:07 WARN readiness check failed error="closed pool"1704--- PASS: TestService_readinessHandler (0.55s)1705=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17062026/09/21 14:06:07 INFO Received complete multipart upload request method=POST path=/17072026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.99ms)17082026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000017092026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.57ms)17102026/09/21 14:06:07 OK 20241026095416_initial_model.sql (9.06ms)17112026/09/21 14:06:07 OK 2_object_stats_trigger.sql (2.11ms)17122026/09/21 14:06:07 goose: up to current file version: 217132026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (2.42ms)17142026/09/21 14:06:07 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTEyZWZkNDctMzA4Yy00YjA4LThjMzctYmE5YzZhMDQ3OWQxLjYyYTMyOTM4LWMxMzYtNGEzMi05YzlhLTRiNzBiNGQzMmQ5ZXgxNzg5OTk5NTY2OTM5MTQyMDQ1 parts=1217152026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures17162026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.26ms)1717--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.33s)1718=== CONT TestClientErrorHandling/InvalidStorePath17192026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)17202026-09-21 14:06:07.500 UTC [814] ERROR: relation "goose_db_version" does not exist at character 3617212026-09-21 14:06:07.500 UTC [814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17222026/09/21 14:06:07 OK 20260905000000_add_claims.sql (3.19ms)17232026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.38ms)17242026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000017252026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.97ms)17262026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.65ms)17272026/09/21 14:06:07 goose: up to current file version: 21728--- PASS: TestService_healthCheckHandler (0.54s)17292026/09/21 14:06:07 OK 20241026095416_initial_model.sql (7.88ms)1730=== CONT TestClientErrorHandling/ServerNotAvailable17312026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)17322026-09-21 14:06:07.516 UTC [817] ERROR: relation "goose_db_version" does not exist at character 3617332026-09-21 14:06:07.516 UTC [817] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17342026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.3ms)17352026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (2.72ms)17362026/09/21 14:06:07 OK 20260905000000_add_claims.sql (3ms)17372026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17382026-09-21 14:06:07.527 UTC [836] ERROR: relation "goose_db_version" does not exist at character 3617392026-09-21 14:06:07.527 UTC [836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17402026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (3.18ms)17412026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000017422026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.58ms)17432026/09/21 14:06:07 OK 1_commit_pending_closure.sql (3.05ms)17442026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)17452026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.44ms)17462026/09/21 14:06:07 goose: up to current file version: 217472026/09/21 14:06:07 OK 20251218171726_add_pins.sql (2.82ms)17482026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)1749=== CONT TestClientErrorHandling/InvalidAuthToken17502026/09/21 14:06:07 OK 20241026095416_initial_model.sql (7.47ms)17512026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.42ms)17522026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)17532026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (2.97ms)17542026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000017552026/09/21 14:06:07 OK 20251218171726_add_pins.sql (2.59ms)17562026/09/21 14:06:07 INFO lead: acquired remote=192.0.2.1:123417572026/09/21 14:06:07 INFO lead: released remote=192.0.2.1:12341758--- PASS: TestLeadEndsOnShutdown (0.55s)1759=== CONT TestResolveDBConnectionString/flag_wins1760=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1761=== CONT TestResolveDBConnectionString/nothing_configured1762=== CONT TestResolveDBConnectionString/missing_file_is_an_error1763=== CONT TestResolveDBConnectionString/file_when_flag_empty1764=== CONT TestCacheConfigHandler/full_config,_no_issuer17652026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.36ms)1766=== CONT TestCacheConfigHandler/no_signing_keys1767=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1768=== CONT TestCacheConfigHandler/no_cache_url_configured1769--- PASS: TestCacheConfigHandler (0.00s)1770 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1771 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1772 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1773 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1774--- PASS: TestResolveDBConnectionString (0.00s)1775 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1776 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1777 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1778 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1779 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17802026/09/21 14:06:07 OK 2_object_stats_trigger.sql (1.64ms)17812026/09/21 14:06:07 goose: up to current file version: 217822026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)17832026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.32ms)17842026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (3.02ms)17852026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000017862026/09/21 14:06:07 OK 1_commit_pending_closure.sql (2.1ms)17872026/09/21 14:06:07 OK 2_object_stats_trigger.sql (2ms)17882026/09/21 14:06:07 goose: up to current file version: 217892026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures17902026/09/21 14:06:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17912026/09/21 14:06:07 INFO Uploading 5g3zs2cdzvpiw0rr9pk5nbns2ajiy0ik-file1.txt (160B)17922026/09/21 14:06:07 INFO lead: acquired remote=192.0.2.1:123417932026-09-21 14:06:07.577 UTC [874] ERROR: relation "goose_db_version" does not exist at character 3617942026-09-21 14:06:07.577 UTC [874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17952026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17962026/09/21 14:06:07 WARN Failed to register uploaded object key=5g3zs2cdzvpiw0rr9pk5nbns2ajiy0ik.ls error="server returned 404: 404 page not found\n"17972026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17982026/09/21 14:06:07 INFO Signed narinfos id=1 count=117992026/09/21 14:06:07 INFO Uploading 1 narinfos18002026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18012026/09/21 14:06:07 WARN Failed to register uploaded object key=5g3zs2cdzvpiw0rr9pk5nbns2ajiy0ik.narinfo error="server returned 404: 404 page not found\n"18022026/09/21 14:06:07 OK 20241026095416_initial_model.sql (8.78ms)18032026/09/21 14:06:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18042026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)18052026/09/21 14:06:07 INFO Completed upload id=118062026/09/21 14:06:07 INFO Upload complete. (110ms)1807=== NAME TestNARDeduplicationMetadataUploadBug1808 metadata_upload_test.go:54: Retrieved narinfo from S3:1809 StorePath: /build/TestNARDeduplicationMetadataUploadBug3458144232/001/store/5g3zs2cdzvpiw0rr9pk5nbns2ajiy0ik-file1.txt1810 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1811 Compression: zstd1812 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1813 NarSize: 1601814 References: 1815 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18162026/09/21 14:06:07 OK 20251218171726_add_pins.sql (3.01ms)1817 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1818 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1819 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18202026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (12.74ms)18212026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.5ms)18222026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (1.71ms)18232026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000018242026/09/21 14:06:07 OK 1_commit_pending_closure.sql (1.61ms)18252026/09/21 14:06:07 OK 2_object_stats_trigger.sql (745.82µs)18262026/09/21 14:06:07 goose: up to current file version: 218272026-09-21 14:06:07.618 UTC [895] ERROR: relation "goose_db_version" does not exist at character 3618282026-09-21 14:06:07.618 UTC [895] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18292026/09/21 14:06:07 OK 20241026095416_initial_model.sql (6.55ms)18302026/09/21 14:06:07 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)18312026/09/21 14:06:07 OK 20251218171726_add_pins.sql (1.87ms)18322026/09/21 14:06:07 OK 20260628120000_add_object_size_and_stats.sql (2.02ms)18332026/09/21 14:06:07 OK 20260905000000_add_claims.sql (2.19ms)1834 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3458144232/001/store/n61fz9dr5pybwx7qi1wqqh7azmy6kn1x-file2.txt18352026/09/21 14:06:07 OK 20260920000000_drop_claims.sql (1.47ms)18362026/09/21 14:06:07 goose: successfully migrated database to version: 2026092000000018372026/09/21 14:06:07 OK 1_commit_pending_closure.sql (1.23ms)18382026/09/21 14:06:07 OK 2_object_stats_trigger.sql (586.01µs)18392026/09/21 14:06:07 goose: up to current file version: 21840=== NAME TestPinProtectsFromGC1841 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3808535089/001/store/vgci2xacrshy0bnz39zzapcpw4inimdf-pinned-file.txt1842 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3808535089/001/store/pr0mlwqv1ry18033lwjw09p1x68x32m1-unpinned-file.txt18432026/09/21 14:06:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.350619ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18442026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1845=== NAME TestClientMultipleUploads1846 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1568017736/001/store/jd4zmlnz6m1mlk2x4w4hi371a5wf799s-test-file-0.txt18472026/09/21 14:06:07 INFO lead: released remote=192.0.2.1:123418482026/09/21 14:06:07 INFO Aborted multipart uploads count=018492026/09/21 14:06:07 WARN Force mode enabled - objects will be deleted immediately without grace period18502026/09/21 14:06:07 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/21 14:06:07 INFO Vacuumed table table=pending_closures18522026/09/21 14:06:07 INFO Vacuumed table table=pending_objects18532026/09/21 14:06:07 INFO Vacuumed table table=multipart_uploads18542026/09/21 14:06:07 INFO Vacuumed table table=closures18552026/09/21 14:06:07 INFO Vacuumed table table=objects1856=== NAME TestClientWithDependencies1857 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies402826240/001/store/avhvn5j7vk1j01vnwyfhsv43ms94819k-test-script1858--- PASS: TestGCMetrics (0.50s)1859=== NAME TestClientIntegration1860 client_integration_test.go:286: Created store path: /build/TestClientIntegration4237581871/002/store/8s3nra06kqb7bxvjwm5n8hc021rqk0li-test-file.txt18612026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures1862=== RUN TestService_RequireScope_OIDC/builder_may_write1863=== PAUSE TestService_RequireScope_OIDC/builder_may_write1864=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1865=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1866=== RUN TestService_RequireScope_OIDC/ops_may_admin1867=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1868=== RUN TestService_RequireScope_OIDC/ops_may_not_write1869=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1870=== RUN TestService_RequireScope_OIDC/reader_may_not_write1871=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1872=== RUN TestService_RequireScope_OIDC/static_token_may_admin1873=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1874=== RUN TestService_RequireScope_OIDC/static_token_may_write1875=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1876=== RUN TestService_RequireScope_OIDC/reader_may_read1877=== PAUSE TestService_RequireScope_OIDC/reader_may_read1878=== RUN TestService_RequireScope_OIDC/writer_implies_read1879=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1880=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1881=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1882=== CONT TestService_RequireScope_OIDC/builder_may_write1883=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1884=== CONT TestService_RequireScope_OIDC/reader_may_read18852026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1886=== CONT TestService_RequireScope_OIDC/static_token_may_admin1887=== CONT TestService_RequireScope_OIDC/ops_may_admin1888=== CONT TestService_RequireScope_OIDC/writer_implies_read1889=== NAME TestClientMultipleUploads1890 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1568017736/001/store/awq565qg8fczhgwlr74rzrblmy7yn6sx-test-file-1.txt1891=== CONT TestService_RequireScope_OIDC/ops_may_not_write18922026/09/21 14:06:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1893=== CONT TestService_RequireScope_OIDC/reader_may_not_write1894=== CONT TestService_RequireScope_OIDC/static_token_may_write1895=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1896--- PASS: TestService_RequireScope_OIDC (0.50s)1897 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1898 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1899 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19072026/09/21 14:06:07 WARN Failed to register uploaded object key=n61fz9dr5pybwx7qi1wqqh7azmy6kn1x.ls error="server returned 404: 404 page not found\n"19082026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19092026/09/21 14:06:07 INFO Signed narinfos id=2 count=119102026/09/21 14:06:07 INFO Uploading 1 narinfos19112026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19122026/09/21 14:06:07 WARN Failed to register uploaded object key=n61fz9dr5pybwx7qi1wqqh7azmy6kn1x.narinfo error="server returned 404: 404 page not found\n"19132026/09/21 14:06:07 INFO Completed upload id=219142026/09/21 14:06:07 INFO Upload complete. (94ms)1915--- PASS: TestService_ReadAuthMiddleware (0.46s)1916=== NAME TestNARDeduplicationMetadataUploadBug1917 metadata_upload_test.go:76: Retrieved narinfo from S3:1918 StorePath: /build/TestNARDeduplicationMetadataUploadBug3458144232/001/store/n61fz9dr5pybwx7qi1wqqh7azmy6kn1x-file2.txt1919 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1920 Compression: zstd1921 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1922 NarSize: 1601923 References: 1924 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1925 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1926 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1927 {"version":1,"root":{"type":"regular","size":44}}1928=== NAME TestClientWithDependencies1929 client_integration_test.go:615: Found 1 dependencies (including self)1930--- PASS: TestNARDeduplicationMetadataUploadBug (0.99s)19312026/09/21 14:06:07 INFO lead: acquired remote=192.0.2.1:123419322026/09/21 14:06:07 INFO lead: released remote=192.0.2.1:12341933--- PASS: TestLeadElectsOneAndHandsOver (0.68s)19342026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1935=== NAME TestClientMultipleUploads1936 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1568017736/001/store/6wh94nvmg6dwiwr6qf6iyc2jx18hrfwd-test-file-2.txt19372026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures19382026/09/21 14:06:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19392026/09/21 14:06:07 INFO Uploading vgci2xacrshy0bnz39zzapcpw4inimdf-pinned-file.txt (128B)19402026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19412026/09/21 14:06:07 WARN Failed to register uploaded object key=vgci2xacrshy0bnz39zzapcpw4inimdf.ls error="server returned 404: 404 page not found\n"19422026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19432026/09/21 14:06:07 INFO Signed narinfos id=1 count=119442026/09/21 14:06:07 INFO Uploading 1 narinfos19452026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19462026/09/21 14:06:07 WARN Failed to register uploaded object key=vgci2xacrshy0bnz39zzapcpw4inimdf.narinfo error="server returned 404: 404 page not found\n"19472026/09/21 14:06:07 INFO Completed upload id=119482026/09/21 14:06:07 INFO Upload complete. (92ms)1949--- PASS: TestCacheStatsHandler (0.48s)19502026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures19512026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1952=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1953=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1954=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1955=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1956=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1957=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1958=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1959=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1960=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1961=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1962=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19632026/09/21 14:06:07 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]1964=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19652026/09/21 14:06:07 WARN Authentication failed token_preview=eyJhbGciOi...qGvqp9M-Xg token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1966--- PASS: TestService_AuthMiddleware_OIDC (0.45s)1967 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1968 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1969 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1970 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19712026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19722026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures19732026/09/21 14:06:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19742026/09/21 14:06:07 INFO Uploading avhvn5j7vk1j01vnwyfhsv43ms94819k-test-script (136B)1975--- PASS: TestService_ReadScope_PublicByDefault (0.44s)19762026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19772026/09/21 14:06:07 WARN Failed to register uploaded object key=log/iwzphgy4yi4yg12fl4i1ah9k3i0k97dl-test-script.drv error="server returned 404: 404 page not found\n"19782026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19792026/09/21 14:06:07 WARN Failed to register uploaded object key=avhvn5j7vk1j01vnwyfhsv43ms94819k.ls error="server returned 404: 404 page not found\n"19802026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19812026/09/21 14:06:07 INFO Signed narinfos id=1 count=119822026/09/21 14:06:07 INFO Uploading 1 narinfos19832026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures19842026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19852026/09/21 14:06:07 WARN Failed to register uploaded object key=avhvn5j7vk1j01vnwyfhsv43ms94819k.narinfo error="server returned 404: 404 page not found\n"19862026/09/21 14:06:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19872026/09/21 14:06:07 INFO Uploading 8s3nra06kqb7bxvjwm5n8hc021rqk0li-test-file.txt (152B)19882026/09/21 14:06:07 INFO Completed upload id=119892026/09/21 14:06:07 INFO Upload complete. (59ms)1990=== NAME TestClientWithDependencies1991 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies402826240/001/store) requires matching store prefix19922026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1993=== NAME TestClientCADerivations1994 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2801946899/001/store/fxygyy88rq8dvhslzjpipq2a24prhxwc-ca-test19952026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19962026/09/21 14:06:07 WARN Failed to register uploaded object key=8s3nra06kqb7bxvjwm5n8hc021rqk0li.ls error="server returned 404: 404 page not found\n"19972026/09/21 14:06:07 INFO Signed narinfos id=1 count=119982026/09/21 14:06:07 INFO Uploading 1 narinfos19992026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2000--- PASS: TestClientWithDependencies (0.73s)20012026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20022026/09/21 14:06:07 WARN Failed to register uploaded object key=8s3nra06kqb7bxvjwm5n8hc021rqk0li.narinfo error="server returned 404: 404 page not found\n"20032026/09/21 14:06:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20042026/09/21 14:06:07 WARN mTLS auth: bound subjects configured but subject DN unavailable20052026/09/21 14:06:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2006--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.45s)20072026/09/21 14:06:07 INFO Completed upload id=120082026/09/21 14:06:07 INFO Upload complete. (95ms)20092026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures20102026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures20112026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20122026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures20132026/09/21 14:06:07 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20142026/09/21 14:06:07 INFO Uploading 6wh94nvmg6dwiwr6qf6iyc2jx18hrfwd-test-file-2.txt (160B)20152026/09/21 14:06:07 INFO Uploading jd4zmlnz6m1mlk2x4w4hi371a5wf799s-test-file-0.txt (160B)20162026/09/21 14:06:07 INFO Uploading awq565qg8fczhgwlr74rzrblmy7yn6sx-test-file-1.txt (160B)20172026/09/21 14:06:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.19696ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20182026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20192026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"2020=== NAME TestClientCADerivations2021 client_ca_test.go:139: Found 1 dependencies (including self)2022--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.46s)20232026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20242026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures20252026/09/21 14:06:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20262026/09/21 14:06:07 INFO Uploading pr0mlwqv1ry18033lwjw09p1x68x32m1-unpinned-file.txt (128B)20272026/09/21 14:06:07 WARN Failed to register uploaded object key=jd4zmlnz6m1mlk2x4w4hi371a5wf799s.ls error="server returned 404: 404 page not found\n"20282026/09/21 14:06:07 WARN Failed to register uploaded object key=6wh94nvmg6dwiwr6qf6iyc2jx18hrfwd.ls error="server returned 404: 404 page not found\n"20292026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20302026/09/21 14:06:07 WARN Failed to register uploaded object key=awq565qg8fczhgwlr74rzrblmy7yn6sx.ls error="server returned 404: 404 page not found\n"20312026/09/21 14:06:07 INFO Signed narinfos id=1 count=120322026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20332026/09/21 14:06:07 INFO Signed narinfos id=2 count=120342026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20352026/09/21 14:06:07 INFO Signed narinfos id=3 count=120362026/09/21 14:06:07 INFO Uploading 3 narinfos20372026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20382026/09/21 14:06:07 WARN Failed to register uploaded object key=6wh94nvmg6dwiwr6qf6iyc2jx18hrfwd.narinfo error="server returned 404: 404 page not found\n"20392026/09/21 14:06:07 WARN Failed to register uploaded object key=jd4zmlnz6m1mlk2x4w4hi371a5wf799s.narinfo error="server returned 404: 404 page not found\n"20402026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20412026/09/21 14:06:07 WARN Failed to register uploaded object key=awq565qg8fczhgwlr74rzrblmy7yn6sx.narinfo error="server returned 404: 404 page not found\n"20422026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20432026/09/21 14:06:07 INFO Signed narinfos id=2 count=120442026/09/21 14:06:07 WARN Failed to register uploaded object key=pr0mlwqv1ry18033lwjw09p1x68x32m1.ls error="server returned 404: 404 page not found\n"20452026/09/21 14:06:07 INFO Uploading 1 narinfos20462026/09/21 14:06:07 INFO All 1 paths already cached20472026/09/21 14:06:07 INFO Completed upload id=12048=== NAME TestClientIntegration2049 client_integration_test.go:312: Retrieved narinfo from S3:20502026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2051 StorePath: /build/TestClientIntegration4237581871/002/store/8s3nra06kqb7bxvjwm5n8hc021rqk0li-test-file.txt2052 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2053 Compression: zstd2054 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12055 NarSize: 1522056 References: 2057 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk120582026/09/21 14:06:07 INFO Completed upload id=220592026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20602026/09/21 14:06:07 INFO Completed upload id=320612026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20622026/09/21 14:06:07 INFO Upload complete. (102ms)2063=== NAME TestClientMultipleUploads2064 client_integration_test.go:369: Uploaded 3 paths in 133.363464ms20652026/09/21 14:06:07 WARN Failed to register uploaded object key=pr0mlwqv1ry18033lwjw09p1x68x32m1.narinfo error="server returned 404: 404 page not found\n"2066=== NAME TestClientIntegration2067 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)20682026/09/21 14:06:07 INFO Completed upload id=22069 client_integration_test.go:313: Decompressed .ls content (64 bytes):2070 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}20712026/09/21 14:06:07 INFO Upload complete. (78ms)2072 client_integration_test.go:316: Testing garbage collection...20732026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures20742026/09/21 14:06:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20752026/09/21 14:06:07 INFO Uploading xv1nv7chnjcsk81pysqammj4a8y976bl-shared-dep (136B)2076--- PASS: TestClientMultipleUploads (0.78s)20772026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20782026/09/21 14:06:07 WARN Failed to register uploaded object key=xv1nv7chnjcsk81pysqammj4a8y976bl.ls error="server returned 404: 404 page not found\n"20792026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20802026/09/21 14:06:07 INFO Signed narinfos id=2 count=120812026/09/21 14:06:07 INFO Uploading 1 narinfos20822026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20832026/09/21 14:06:07 WARN Failed to register uploaded object key=xv1nv7chnjcsk81pysqammj4a8y976bl.narinfo error="server returned 404: 404 page not found\n"20842026/09/21 14:06:07 INFO Completed upload id=220852026/09/21 14:06:07 INFO Upload complete. (93ms)20862026/09/21 14:06:07 INFO Received uploads request method=POST path=/api/pending_closures20872026/09/21 14:06:07 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20882026/09/21 14:06:07 INFO Uploading bxqf34nlpjdvyqz6dq0jcyda23hs8fjw-top (224B)20892026/09/21 14:06:07 INFO Uploading xv1nv7chnjcsk81pysqammj4a8y976bl-shared-dep (136B)20902026/09/21 14:06:07 INFO Received create pin request method=POST path=/api/pins/myapp20912026/09/21 14:06:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures20922026/09/21 14:06:07 INFO Garbage collection started20932026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/09jf8pnd1dfr0c4xsavryqhjv83zyfifigkvdgcn4kbcgv8k7i3b.nar.zst error="server returned 404: 404 page not found\n"20942026/09/21 14:06:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20952026/09/21 14:06:07 WARN Failed to register uploaded object key=bxqf34nlpjdvyqz6dq0jcyda23hs8fjw.ls error="server returned 404: 404 page not found\n"20962026/09/21 14:06:07 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3808535089/001/store/vgci2xacrshy0bnz39zzapcpw4inimdf-pinned-file.txt narinfo_key=vgci2xacrshy0bnz39zzapcpw4inimdf.narinfo20972026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20982026/09/21 14:06:07 WARN Failed to register uploaded object key=xv1nv7chnjcsk81pysqammj4a8y976bl.ls error="server returned 404: 404 page not found\n"20992026/09/21 14:06:07 INFO Signed narinfos id=1 count=121002026/09/21 14:06:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21012026/09/21 14:06:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures21022026/09/21 14:06:07 INFO Signed narinfos id=3 count=121032026/09/21 14:06:07 INFO Garbage collection started21042026/09/21 14:06:07 INFO Uploading 2 narinfos21052026/09/21 14:06:07 INFO Aborted multipart uploads count=021062026/09/21 14:06:07 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/09/21 14:06:07 WARN Failed to register uploaded object key=bxqf34nlpjdvyqz6dq0jcyda23hs8fjw.narinfo error="server returned 404: 404 page not found\n"21082026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21092026/09/21 14:06:07 WARN Failed to register uploaded object key=xv1nv7chnjcsk81pysqammj4a8y976bl.narinfo error="server returned 404: 404 page not found\n"21102026/09/21 14:06:07 INFO Completed upload id=121112026/09/21 14:06:07 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21122026/09/21 14:06:07 INFO Aborted multipart uploads count=021132026/09/21 14:06:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21142026/09/21 14:06:07 INFO Completed upload id=321152026/09/21 14:06:07 INFO Upload complete. (224ms)2116=== NAME TestClientSharedPathCommittedMidPush2117 client_integration_test.go:680: Retrieved narinfo from S3:2118 StorePath: /build/TestClientSharedPathCommittedMidPush1289999481/001/store/xv1nv7chnjcsk81pysqammj4a8y976bl-shared-dep2119 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2120 Compression: zstd2121 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822122 NarSize: 1362123 References: 2124 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21252026/09/21 14:06:07 WARN Force mode enabled - objects will be deleted immediately without grace period2126 client_integration_test.go:680: Retrieved narinfo from S3:2127 StorePath: /build/TestClientSharedPathCommittedMidPush1289999481/001/store/bxqf34nlpjdvyqz6dq0jcyda23hs8fjw-top2128 URL: nar/09jf8pnd1dfr0c4xsavryqhjv83zyfifigkvdgcn4kbcgv8k7i3b.nar.zst2129 Compression: zstd2130 NarHash: sha256:09jf8pnd1dfr0c4xsavryqhjv83zyfifigkvdgcn4kbcgv8k7i3b2131 NarSize: 2242132 References: /build/TestClientSharedPathCommittedMidPush1289999481/001/store/xv1nv7chnjcsk81pysqammj4a8y976bl-shared-dep2133 CA: text:sha256:1bf67swv1sjfwnsyz95wlcgarx0c11bwd8kqvqwdvic28rjcwd182134--- PASS: TestClientSharedPathCommittedMidPush (0.84s)21352026/09/21 14:06:08 INFO Received uploads request method=POST path=/api/pending_closures21362026/09/21 14:06:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21372026/09/21 14:06:08 INFO Uploading fxygyy88rq8dvhslzjpipq2a24prhxwc-ca-test (144B)2138--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2139 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)2140 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2141 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.63s)21422026/09/21 14:06:08 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21432026/09/21 14:06:08 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21442026/09/21 14:06:08 WARN Failed to register uploaded object key=log/v9s0zcqgm13xz5hgrfdx9qipsq9bs2n5-ca-test.drv error="server returned 404: 404 page not found\n"21452026/09/21 14:06:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21462026/09/21 14:06:08 WARN Failed to register uploaded object key=fxygyy88rq8dvhslzjpipq2a24prhxwc.ls error="server returned 404: 404 page not found\n"21472026/09/21 14:06:08 INFO Signed narinfos id=1 count=121482026/09/21 14:06:08 INFO Uploading 1 narinfos21492026/09/21 14:06:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21502026/09/21 14:06:08 WARN Failed to register uploaded object key=fxygyy88rq8dvhslzjpipq2a24prhxwc.narinfo error="server returned 404: 404 page not found\n"21512026/09/21 14:06:08 INFO Completed upload id=121522026/09/21 14:06:08 INFO Upload complete. (169ms)2153=== NAME TestClientCADerivations2154 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2801946899/001/store/fxygyy88rq8dvhslzjpipq2a24prhxwc-ca-test2155 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2156 Compression: zstd2157 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2158 NarSize: 1442159 References: 2160 Deriver: /build/TestClientCADerivations2801946899/001/store/v9s0zcqgm13xz5hgrfdx9qipsq9bs2n5-ca-test.drv2161 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2162 client_ca_test.go:185: Checking for realisation files in S3...2163 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2164 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21652026/09/21 14:06:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21662026/09/21 14:06:08 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2167 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2168 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2169 error: binary cache 's3://bucket49?endpoint=http://localhost:38999®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2801946899/001/store'2170 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12171--- PASS: TestClientCADerivations (0.93s)21722026/09/21 14:06:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=832.857609ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2173=== NAME TestOrphanedObjectsGCStressTest2174 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2175 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2176 orphaned_objects_gc_test.go:509: Stress test completed successfully:2177 orphaned_objects_gc_test.go:510: - Active objects preserved: 202178 orphaned_objects_gc_test.go:511: - Objects deleted: 2102179 orphaned_objects_gc_test.go:512: - Total GC'd: 2102180--- PASS: TestOrphanedObjectsGCStressTest (2.56s)21812026/09/21 14:06:08 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=021822026/09/21 14:06:08 INFO Vacuumed table table=pending_closures21832026/09/21 14:06:08 INFO Vacuumed table table=pending_objects21842026/09/21 14:06:08 INFO Vacuumed table table=multipart_uploads21852026/09/21 14:06:08 INFO Vacuumed table table=closures21862026/09/21 14:06:08 INFO Vacuumed table table=objects21872026/09/21 14:06:08 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=021882026/09/21 14:06:08 INFO Vacuumed table table=pending_closures21892026/09/21 14:06:08 INFO Vacuumed table table=pending_objects21902026/09/21 14:06:08 INFO Vacuumed table table=multipart_uploads21912026/09/21 14:06:08 INFO Vacuumed table table=closures21922026/09/21 14:06:08 INFO Vacuumed table table=objects21932026/09/21 14:06:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.506818866s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21942026/09/21 14:06:09 WARN Rate limiter enabled after throttle name=s3-test rate=521952026/09/21 14:06:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2196=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2197 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102198 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002199--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.51s)22002026/09/21 14:06:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02201=== NAME TestClientIntegration2202 client_integration_test.go:323: Objects in database after GC:2203 client_integration_test.go:323: Successfully deleted all objects with GC --force2204--- PASS: TestClientIntegration (2.78s)22052026/09/21 14:06:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02206=== NAME TestPinProtectsFromGC2207 client_integration_test.go:794: Pin successfully protected closure from garbage collection2208--- PASS: TestPinProtectsFromGC (2.86s)22092026/09/21 14:06:10 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-config22102026/09/21 14:06:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.160538ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22112026/09/21 14:06:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.299791ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22122026/09/21 14:06:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=820.889656ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22132026/09/21 14:06:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.458147836s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22142026/09/21 14:06:13 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"22152026/09/21 14:06:13 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_closures22162026/09/21 14:06:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.73769ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22172026/09/21 14:06:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=415.468402ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22182026/09/21 14:06:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=739.347923ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22192026/09/21 14:06:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.674340651s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2220--- PASS: TestClientErrorHandling (0.00s)2221 --- PASS: TestClientErrorHandling/InvalidStorePath (0.46s)2222 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.61s)2223 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.33s)2224PASS22252026-09-21 14:06:17.062 UTC [129] LOG: received smart shutdown request22262026-09-21 14:06:17.068 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122272026-09-21 14:06:17.077 UTC [134] LOG: shutting down22282026-09-21 14:06:17.078 UTC [134] LOG: checkpoint starting: shutdown immediate22292026-09-21 14:06:17.645 UTC [134] LOG: checkpoint complete: wrote 11205 buffers (68.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.236 s, sync=0.300 s, total=0.568 s; sync files=18738, longest=0.002 s, average=0.001 s; distance=255737 kB, estimate=255737 kB; lsn=0/11124278, redo lsn=0/1112427822302026-09-21 14:06:17.717 UTC [129] LOG: database system is shut down2231Running OIDC tests...2232=== RUN TestGlobMatch2233=== PAUSE TestGlobMatch2234=== RUN TestAudienceForIssuer2235=== PAUSE TestAudienceForIssuer2236=== RUN TestValidateToken_ValidToken2237=== PAUSE TestValidateToken_ValidToken2238=== RUN TestValidateToken_WrongAudience2239=== PAUSE TestValidateToken_WrongAudience2240=== RUN TestValidateToken_Expired2241=== PAUSE TestValidateToken_Expired2242=== RUN TestValidateToken_BoundClaimsMismatch2243=== PAUSE TestValidateToken_BoundClaimsMismatch2244=== RUN TestValidateToken_BoundSubjectMismatch2245=== PAUSE TestValidateToken_BoundSubjectMismatch2246=== RUN TestValidateToken_MultipleProviders2247=== PAUSE TestValidateToken_MultipleProviders2248=== RUN TestValidateToken_NoMatchingProvider2249=== PAUSE TestValidateToken_NoMatchingProvider2250=== RUN TestValidateToken_KubernetesServiceAccount2251=== PAUSE TestValidateToken_KubernetesServiceAccount2252=== RUN TestNewValidator_KubernetesRequiresCA2253=== PAUSE TestNewValidator_KubernetesRequiresCA2254=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2255=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2256=== RUN TestScopes_LegacyProviderDefaultsToWrite2257=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2258=== RUN TestScopes_Rules2259=== PAUSE TestScopes_Rules2260=== RUN TestScopes_ConfigValidation2261=== PAUSE TestScopes_ConfigValidation2262=== CONT TestGlobMatch2263=== CONT TestValidateToken_NoMatchingProvider2264=== CONT TestScopes_LegacyProviderDefaultsToWrite2265=== RUN TestGlobMatch/foo_foo2266=== PAUSE TestGlobMatch/foo_foo2267=== RUN TestGlobMatch/foo_bar2268=== PAUSE TestGlobMatch/foo_bar2269=== RUN TestGlobMatch/*_2270=== PAUSE TestGlobMatch/*_2271=== RUN TestGlobMatch/*_anything2272=== PAUSE TestGlobMatch/*_anything2273=== RUN TestGlobMatch/foo*_foo2274=== CONT TestScopes_ConfigValidation2275=== CONT TestValidateToken_MultipleProviders2276=== CONT TestValidateToken_BoundSubjectMismatch2277=== CONT TestValidateToken_BoundClaimsMismatch2278=== CONT TestValidateToken_Expired2279=== CONT TestValidateToken_WrongAudience2280=== CONT TestValidateToken_ValidToken2281=== CONT TestAudienceForIssuer2282=== CONT TestScopes_Rules2283=== CONT TestNewValidator_KubernetesRequiresCA2284=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2285=== CONT TestValidateToken_KubernetesServiceAccount2286=== PAUSE TestGlobMatch/foo*_foo2287=== RUN TestGlobMatch/foo*_foobar2288--- PASS: TestAudienceForIssuer (0.00s)2289=== PAUSE TestGlobMatch/foo*_foobar2290=== RUN TestGlobMatch/foo*_bar2291=== PAUSE TestGlobMatch/foo*_bar2292=== RUN TestGlobMatch/*bar_bar2293=== PAUSE TestGlobMatch/*bar_bar2294=== RUN TestGlobMatch/*bar_foobar2295=== PAUSE TestGlobMatch/*bar_foobar2296=== RUN TestGlobMatch/*bar_foo2297=== PAUSE TestGlobMatch/*bar_foo2298=== RUN TestGlobMatch/foo*bar_foobar2299=== PAUSE TestGlobMatch/foo*bar_foobar2300=== RUN TestGlobMatch/foo*bar_foo123bar2301=== PAUSE TestGlobMatch/foo*bar_foo123bar2302=== RUN TestGlobMatch/foo*bar_foobarbaz2303=== PAUSE TestGlobMatch/foo*bar_foobarbaz2304=== RUN TestGlobMatch/*/*_foo/bar2305=== PAUSE TestGlobMatch/*/*_foo/bar2306=== RUN TestGlobMatch/*/*_foo2307=== PAUSE TestGlobMatch/*/*_foo2308=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2309=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2310=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02311=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02312=== RUN TestGlobMatch/refs/*/main_refs/heads/main2313=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2314=== RUN TestGlobMatch/fo?_foo2315=== PAUSE TestGlobMatch/fo?_foo2316=== RUN TestGlobMatch/fo?_fo2317=== PAUSE TestGlobMatch/fo?_fo2318--- PASS: TestScopes_ConfigValidation (0.01s)2319=== RUN TestGlobMatch/fo?_fooo2320=== PAUSE TestGlobMatch/fo?_fooo2321=== RUN TestGlobMatch/?oo_foo2322=== PAUSE TestGlobMatch/?oo_foo2323=== RUN TestGlobMatch/?oo_boo2324=== PAUSE TestGlobMatch/?oo_boo2325=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2326=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2327=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2328=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2329=== CONT TestGlobMatch/foo_foo2330=== CONT TestGlobMatch/*/*_foo/bar2331=== CONT TestGlobMatch/foo_bar2332=== CONT TestGlobMatch/foo*bar_foobarbaz2333=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02334=== CONT TestGlobMatch/refs/*/main_refs/heads/main2335=== CONT TestGlobMatch/fo?_fo2336=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2337=== CONT TestGlobMatch/foo*bar_foo123bar2338=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2339=== CONT TestGlobMatch/?oo_boo2340=== CONT TestGlobMatch/?oo_foo2341=== CONT TestGlobMatch/fo?_fooo2342=== CONT TestGlobMatch/foo*bar_foobar2343=== CONT TestGlobMatch/*bar_foo2344=== CONT TestGlobMatch/*bar_foobar2345=== CONT TestGlobMatch/*bar_bar2346=== CONT TestGlobMatch/foo*_bar2347=== CONT TestGlobMatch/foo*_foobar2348=== CONT TestGlobMatch/foo*_foo2349=== CONT TestGlobMatch/*_anything2350=== CONT TestGlobMatch/*_2351=== CONT TestGlobMatch/fo?_foo23522026/09/21 14:06:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38179/oidc23532026/09/21 14:06:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39189/oidc23542026/09/21 14:06:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45659/oidc23552026/09/21 14:06:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42897/oidc23562026/09/21 14:06:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40747/oidc2357=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main23582026/09/21 14:06:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42079/oidc2359=== CONT TestGlobMatch/*/*_foo2360--- PASS: TestGlobMatch (0.01s)2361 --- PASS: TestGlobMatch/foo_foo (0.00s)2362 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2363 --- PASS: TestGlobMatch/foo_bar (0.00s)2364 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2365 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2366 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2367 --- PASS: TestGlobMatch/fo?_fo (0.00s)2368 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2369 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2370 --- PASS: TestGlobMatch/?oo_boo (0.00s)2371 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2372 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2373 --- PASS: TestGlobMatch/?oo_foo (0.00s)2374 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2375 --- PASS: TestGlobMatch/*bar_foo (0.00s)2376 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2377 --- PASS: TestGlobMatch/*bar_bar (0.00s)2378 --- PASS: TestGlobMatch/foo*_bar (0.00s)2379 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2380 --- PASS: TestGlobMatch/foo*_foo (0.00s)2381 --- PASS: TestGlobMatch/*_anything (0.00s)2382 --- PASS: TestGlobMatch/fo?_foo (0.00s)2383 --- PASS: TestGlobMatch/*_ (0.00s)2384 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2385 --- PASS: TestGlobMatch/*/*_foo (0.00s)23862026/09/21 14:06:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40811/oidc23872026/09/21 14:06:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43141/oidc23882026/09/21 14:06:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43603/oidc23892026/09/21 14:06:19 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42073/oidc23902026/09/21 14:06:19 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232391--- PASS: TestValidateToken_Expired (0.02s)2392--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2393--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2394--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2395--- PASS: TestValidateToken_ValidToken (0.01s)23962026/09/21 14:06:19 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:464972397--- PASS: TestValidateToken_WrongAudience (0.02s)2398--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2399--- PASS: TestValidateToken_MultipleProviders (0.02s)2400--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2401--- PASS: TestScopes_Rules (0.02s)2402--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)24032026/09/21 14:06:19 http: TLS handshake error from 127.0.0.1:50266: remote error: tls: bad certificate2404--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2405PASS2406Running hook tests...2407=== RUN TestSendPathsEmpty2408=== PAUSE TestSendPathsEmpty2409=== RUN TestQueueEnqueueAndFetch2410=== PAUSE TestQueueEnqueueAndFetch2411=== RUN TestQueueDeduplication2412=== PAUSE TestQueueDeduplication2413=== RUN TestQueueRemove2414=== PAUSE TestQueueRemove2415=== RUN TestQueueFetchBatchLimit2416=== PAUSE TestQueueFetchBatchLimit2417=== RUN TestQueueRetryMovesToBack2418=== PAUSE TestQueueRetryMovesToBack2419=== RUN TestQueueFetchRemoveLifecycle2420=== PAUSE TestQueueFetchRemoveLifecycle2421=== RUN TestQueueConcurrentWriters2422=== PAUSE TestQueueConcurrentWriters2423=== RUN TestQueueRemoveLargeClosure2424=== PAUSE TestQueueRemoveLargeClosure2425=== RUN TestServerClientIntegration2426=== PAUSE TestServerClientIntegration2427=== RUN TestServerQueueError2428=== PAUSE TestServerQueueError2429=== RUN TestGetListenerSocketActivation2430 server_test.go:210: === RUN TestGetListenerSocketActivation2431 --- PASS: TestGetListenerSocketActivation (0.00s)2432 PASS2433 2434--- PASS: TestGetListenerSocketActivation (0.01s)2435=== RUN TestDrainIsolatesPoisonPath2436=== PAUSE TestDrainIsolatesPoisonPath2437=== RUN TestRunNotBlockedByPoisonHead2438=== PAUSE TestRunNotBlockedByPoisonHead2439=== RUN TestDrainGivesUpWhenServerDown2440=== PAUSE TestDrainGivesUpWhenServerDown2441=== RUN TestFailedPathPrunedByLaterClosure2442=== PAUSE TestFailedPathPrunedByLaterClosure2443=== RUN TestWorkerUploadsAndRemoves2444=== PAUSE TestWorkerUploadsAndRemoves2445=== RUN TestWorkerSkipsGCdPaths2446=== PAUSE TestWorkerSkipsGCdPaths2447=== RUN TestWorkerPrunesClosureDeps2448=== PAUSE TestWorkerPrunesClosureDeps2449=== RUN TestDrainTimeout2450=== PAUSE TestDrainTimeout2451=== CONT TestSendPathsEmpty2452=== CONT TestServerQueueError2453=== CONT TestDrainGivesUpWhenServerDown2454=== CONT TestWorkerUploadsAndRemoves2455--- PASS: TestSendPathsEmpty (0.00s)2456=== CONT TestQueueFetchBatchLimit2457=== CONT TestQueueRetryMovesToBack2458=== CONT TestQueueRemove2459=== CONT TestQueueDeduplication2460=== CONT TestServerClientIntegration2461=== CONT TestQueueRemoveLargeClosure24622026/09/21 14:06:19 ERROR Failed to queue paths error="permission denied" count=12463=== CONT TestQueueConcurrentWriters2464=== CONT TestQueueEnqueueAndFetch2465=== CONT TestQueueFetchRemoveLifecycle2466=== CONT TestWorkerPrunesClosureDeps2467--- PASS: TestServerQueueError (0.00s)2468=== CONT TestDrainTimeout2469=== CONT TestFailedPathPrunedByLaterClosure2470=== CONT TestRunNotBlockedByPoisonHead2471=== CONT TestDrainIsolatesPoisonPath2472=== CONT TestWorkerSkipsGCdPaths2473--- PASS: TestServerClientIntegration (0.00s)24742026/09/21 14:06:19 INFO Upload queue status pending=224752026/09/21 14:06:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3823412246/002/nonexistent24762026/09/21 14:06:19 INFO Upload queue status pending=32477--- PASS: TestQueueFetchBatchLimit (0.03s)2478--- PASS: TestQueueEnqueueAndFetch (0.03s)24792026/09/21 14:06:19 INFO Uploading batch count=124802026/09/21 14:06:19 INFO Uploading batch count=124812026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=124822026/09/21 14:06:19 INFO Uploading batch count=124832026/09/21 14:06:19 INFO Upload queue status pending=22484--- PASS: TestQueueRemove (0.03s)24852026/09/21 14:06:19 INFO Uploading batch count=22486--- PASS: TestQueueDeduplication (0.03s)24872026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=124882026/09/21 14:06:19 INFO Uploading batch count=124892026/09/21 14:06:19 INFO Upload queue status pending=224902026/09/21 14:06:19 INFO Uploading batch count=42491--- PASS: TestQueueFetchRemoveLifecycle (0.03s)24922026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=424932026/09/21 14:06:19 INFO Uploading batch count=224942026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=224952026/09/21 14:06:19 INFO Uploading batch count=224962026/09/21 14:06:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3308508731/002/a24972026/09/21 14:06:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4105054116/002/bbb24982026/09/21 14:06:19 INFO Uploading batch count=12499--- PASS: TestQueueRetryMovesToBack (0.03s)25002026/09/21 14:06:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3308508731/002/b25012026/09/21 14:06:19 INFO Uploading batch count=225022026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=225032026/09/21 14:06:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3308508731/002/c25042026/09/21 14:06:19 INFO Uploading batch count=125052026/09/21 14:06:19 INFO Uploading batch count=125062026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=125072026/09/21 14:06:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3308508731/002/d25082026/09/21 14:06:19 INFO Uploading batch count=125092026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=125102026/09/21 14:06:19 INFO Uploading batch count=225112026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=225122026/09/21 14:06:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3308508731/002/e25132026/09/21 14:06:19 INFO Uploading batch count=125142026/09/21 14:06:19 ERROR Upload failed error="upload failed" count=125152026/09/21 14:06:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3308508731/002/f25162026/09/21 14:06:19 ERROR Drain finished with paths left in queue remaining=12517--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)25182026/09/21 14:06:19 ERROR Drain finished with paths left in queue remaining=102519--- PASS: TestDrainIsolatesPoisonPath (0.03s)2520--- PASS: TestDrainGivesUpWhenServerDown (0.04s)2521--- PASS: TestWorkerSkipsGCdPaths (0.04s)2522--- PASS: TestWorkerUploadsAndRemoves (0.05s)2523--- PASS: TestWorkerPrunesClosureDeps (0.05s)2524--- PASS: TestQueueRemoveLargeClosure (0.08s)25252026/09/21 14:06:19 ERROR Upload failed error="context deadline exceeded" count=225262026/09/21 14:06:19 ERROR Drain finished with paths left in queue remaining=42527--- PASS: TestDrainTimeout (0.23s)2528--- PASS: TestQueueConcurrentWriters (0.49s)25292026/09/21 14:06:20 INFO Uploading batch count=125302026/09/21 14:06:20 INFO Uploading batch count=125312026/09/21 14:06:20 INFO Uploading batch count=125322026/09/21 14:06:20 ERROR Upload failed error="upload failed" count=125332026/09/21 14:06:20 INFO Uploading batch count=125342026/09/21 14:06:20 ERROR Upload failed error="upload failed" count=125352026/09/21 14:06:20 INFO Uploading batch count=125362026/09/21 14:06:20 ERROR Upload failed error="upload failed" count=125372026/09/21 14:06:20 INFO Uploading batch count=125382026/09/21 14:06:20 ERROR Upload failed error="upload failed" count=125392026/09/21 14:06:20 ERROR Drain finished with paths left in queue remaining=12540--- PASS: TestRunNotBlockedByPoisonHead (1.05s)2541PASS