niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #231
· 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 TestPartSizeForNAR12=== PAUSE TestPartSizeForNAR13=== RUN TestUploadMultipart_SupersededByPeer14=== PAUSE TestUploadMultipart_SupersededByPeer15=== RUN TestDumpPathCaseHackMatchesNix16--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)17=== RUN TestDumpPathCaseHackCollision18--- PASS: TestDumpPathCaseHackCollision (0.00s)19=== RUN TestDumpPathMatchesNix20=== PAUSE TestDumpPathMatchesNix21=== RUN TestDumpPathSingleFile22=== PAUSE TestDumpPathSingleFile23=== RUN TestDumpPathWriterError24=== PAUSE TestDumpPathWriterError25=== RUN TestEncodeNixBase3226=== PAUSE TestEncodeNixBase3227=== RUN TestEncodeNixBase32WithRealHash28=== PAUSE TestEncodeNixBase32WithRealHash29=== RUN TestConvertHashToNix3230=== PAUSE TestConvertHashToNix3231=== RUN TestGetStorePathHash32=== PAUSE TestGetStorePathHash33=== RUN TestPathInfoHashCompatibility34=== PAUSE TestPathInfoHashCompatibility35=== RUN TestParsePathInfoJSON36=== PAUSE TestParsePathInfoJSON37=== RUN TestParsePathInfoJSONMultiplePaths38=== PAUSE TestParsePathInfoJSONMultiplePaths39=== RUN TestPathInfoCACompatibility40=== PAUSE TestPathInfoCACompatibility41=== RUN TestRateLimiterFeedback42=== PAUSE TestRateLimiterFeedback43=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess44=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== RUN TestResolveStorePath46=== PAUSE TestResolveStorePath47=== RUN TestDoWithRetry_BodyReplayedViaGetBody48=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody49=== RUN TestShellSplit50=== PAUSE TestShellSplit51=== RUN TestShellSplitErrors52=== PAUSE TestShellSplitErrors53=== RUN TestStreamPushReportsEveryPath54=== PAUSE TestStreamPushReportsEveryPath55=== RUN TestStreamPushBatchesUnderLoad56=== PAUSE TestStreamPushBatchesUnderLoad57=== RUN TestStreamPushIsolatesFailures58=== PAUSE TestStreamPushIsolatesFailures59=== RUN TestStreamPushGivesUpOnDeadServer60=== PAUSE TestStreamPushGivesUpOnDeadServer61=== RUN TestStreamPushRequestLine62=== PAUSE TestStreamPushRequestLine63=== RUN TestSetClientTLS64=== PAUSE TestSetClientTLS65=== RUN TestSetClientTLSDoesNotMutateDefaultTransport66=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport67=== RUN TestSetClientTLSErrors68=== PAUSE TestSetClientTLSErrors69=== RUN TestStaticToken70=== PAUSE TestStaticToken71=== RUN TestFileTokenReadsAndCaches72=== PAUSE TestFileTokenReadsAndCaches73=== RUN TestFileTokenMissing74=== PAUSE TestFileTokenMissing75=== RUN TestFileTokenEmpty76=== PAUSE TestFileTokenEmpty77=== RUN TestScriptTokenNoExpiryRerunsEveryCall78=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall79=== RUN TestScriptTokenCachesUntilRefresh80=== PAUSE TestScriptTokenCachesUntilRefresh81=== RUN TestScriptTokenEmptyToken82=== PAUSE TestScriptTokenEmptyToken83=== RUN TestScriptTokenBadJSON84=== PAUSE TestScriptTokenBadJSON85=== RUN TestScriptTokenScriptFails86=== PAUSE TestScriptTokenScriptFails87=== RUN TestScriptTokenEmptyCommand88=== PAUSE TestScriptTokenEmptyCommand89=== CONT TestDoServerRequestAttachesToken90=== CONT TestShellSplit91=== CONT TestConvertHashToNix3292=== RUN TestConvertHashToNix32/SRI_format_to_Nix3293=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3294=== RUN TestConvertHashToNix32/already_Nix32_format95--- PASS: TestShellSplit (0.00s)96=== CONT TestResolveStorePath97=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess98=== CONT TestRateLimiterFeedback99=== RUN TestRateLimiterFeedback/429_enables_limiter100=== PAUSE TestRateLimiterFeedback/429_enables_limiter101=== RUN TestRateLimiterFeedback/503_enables_limiter102=== PAUSE TestRateLimiterFeedback/503_enables_limiter103=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter104=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter105=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter106=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter107=== CONT TestDumpPathSingleFile108=== CONT TestPathInfoCACompatibility109=== RUN TestPathInfoCACompatibility/null_ca_field110=== PAUSE TestPathInfoCACompatibility/null_ca_field111=== RUN TestPathInfoCACompatibility/old_string_format_-_text112=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text113=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive114=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive115=== RUN TestPathInfoCACompatibility/new_structured_format_-_text116=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text117=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method118=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method119=== CONT TestParsePathInfoJSONMultiplePaths120=== CONT TestParsePathInfoJSON121=== CONT TestPathInfoHashCompatibility1222026/09/21 12:56:11 WARN Rate limiter enabled after throttle name=server-test rate=5123=== CONT TestGetStorePathHash124=== CONT TestStreamPushGivesUpOnDeadServer125=== CONT TestSetClientTLSErrors126=== CONT TestSetClientTLSDoesNotMutateDefaultTransport127=== CONT TestStreamPushRequestLine128=== CONT TestStaticToken129=== CONT TestDumpPathMatchesNix130=== CONT TestScriptTokenEmptyCommand131=== CONT TestEncodeNixBase32WithRealHash132=== CONT TestScriptTokenScriptFails133=== CONT TestEncodeNixBase32134=== CONT TestScriptTokenBadJSON135=== CONT TestDumpPathWriterError136=== CONT TestScriptTokenEmptyToken137=== CONT TestDoWithRetry_BodyReplayedViaGetBody138=== PAUSE TestConvertHashToNix32/already_Nix32_format139=== CONT TestScriptTokenCachesUntilRefresh140=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths141=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths142=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths143=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths144=== CONT TestFileTokenReadsAndCaches145=== CONT TestFileTokenEmpty1462026/09/21 12:56:11 ERROR Upload failed error="connection refused" count=201472026/09/21 12:56:11 ERROR Server seems unavailable, giving up on batch untried=17148=== RUN TestParsePathInfoJSON/Nix_format149=== PAUSE TestParsePathInfoJSON/Nix_format150=== CONT TestScriptTokenNoExpiryRerunsEveryCall151--- PASS: TestStaticToken (0.00s)152=== CONT TestFileTokenMissing153--- PASS: TestEncodeNixBase32WithRealHash (0.00s)154--- PASS: TestScriptTokenEmptyCommand (0.00s)155--- PASS: TestResolveStorePath (0.00s)156=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)157=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)158=== RUN TestConvertHashToNix32/invalid_format159=== CONT TestFilterOversizedClosures160=== RUN TestGetStorePathHash/valid_store_path161=== RUN TestParsePathInfoJSON/Lix_format162=== RUN TestEncodeNixBase32/test_string_hash163=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon164--- PASS: TestFileTokenEmpty (0.00s)165=== CONT TestUploadMultipart_SupersededByPeer166=== RUN TestUploadMultipart_SupersededByPeer/exists167=== PAUSE TestUploadMultipart_SupersededByPeer/exists168=== RUN TestUploadMultipart_SupersededByPeer/missing169=== PAUSE TestUploadMultipart_SupersededByPeer/missing170=== CONT TestPartSizeForNAR171=== RUN TestPartSizeForNAR/zero_stays_at_minimum172=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum173=== RUN TestPartSizeForNAR/small_stays_at_minimum1742026/09/21 12:56:11 WARN Rate limiter enabled after throttle name=server-test rate=5175=== PAUSE TestPartSizeForNAR/small_stays_at_minimum176=== CONT TestSetClientTLS1772026/09/21 12:56:11 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:437851782026/09/21 12:56:11 ERROR Upload failed error=boom count=11792026/09/21 12:56:11 WARN Rate limiter backed off name=server-test rate=51802026/09/21 12:56:11 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43785181=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum182--- PASS: TestFileTokenReadsAndCaches (0.00s)183--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)184=== CONT TestStreamPushReportsEveryPath185=== CONT TestStreamPushBatchesUnderLoad186=== PAUSE TestConvertHashToNix32/invalid_format187=== RUN TestFilterOversizedClosures/no_limit_keeps_everything188=== PAUSE TestGetStorePathHash/valid_store_path189=== PAUSE TestParsePathInfoJSON/Lix_format190=== PAUSE TestEncodeNixBase32/test_string_hash191=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon192--- PASS: TestScriptTokenScriptFails (0.00s)193--- PASS: TestFileTokenMissing (0.00s)194--- PASS: TestScriptTokenBadJSON (0.01s)195--- PASS: TestScriptTokenEmptyToken (0.01s)196--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)197=== CONT TestCaseHackSuffix198--- PASS: TestStreamPushReportsEveryPath (0.00s)199=== CONT TestRateLimiterFeedback/503_enables_limiter200=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum201=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts202=== CONT TestRegisterUploadedObjectReusesConnections203=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything204=== CONT TestStreamPushIsolatesFailures205=== RUN TestEncodeNixBase32/empty_input206=== RUN TestSetClientTLSErrors/missing_cert_file207=== RUN TestGetStorePathHash/basename_without_hyphen_should_error208=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI209=== RUN TestParsePathInfoJSON/empty_input210=== CONT TestRateLimiterFeedback/429_enables_limiter211=== CONT TestShellSplitErrors212=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter213=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts214--- PASS: TestDoServerRequestAttachesToken (0.01s)2152026/09/21 12:56:11 ERROR Upload failed error="bad path" count=3216=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter218=== PAUSE TestSetClientTLSErrors/missing_cert_file219=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error220=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI221=== PAUSE TestParsePathInfoJSON/empty_input222=== PAUSE TestEncodeNixBase32/empty_input223=== RUN TestSetClientTLSErrors/missing_key_file224=== CONT TestPathInfoCACompatibility/null_ca_field225=== RUN TestPartSizeForNAR/1_TiB226--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)227--- PASS: TestShellSplitErrors (0.00s)228=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512229=== PAUSE TestSetClientTLSErrors/missing_key_file230=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== RUN TestParsePathInfoJSON/whitespace_only233=== RUN TestSetClientTLSErrors/missing_ca_file234=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error235=== RUN TestFilterOversizedClosures/all_closures_skipped236=== PAUSE TestSetClientTLSErrors/missing_ca_file237=== PAUSE TestFilterOversizedClosures/all_closures_skipped238=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error239--- PASS: TestStreamPushIsolatesFailures (0.00s)240=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive241=== RUN TestSetClientTLSErrors/invalid_ca_file242=== CONT TestPathInfoCACompatibility/new_structured_format_-_text243=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths244=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error245=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error246=== CONT TestPathInfoCACompatibility/old_string_format_-_text247=== CONT TestUploadMultipart_SupersededByPeer/missing248=== CONT TestUploadMultipart_SupersededByPeer/exists2492026/09/21 12:56:11 WARN Rate limiter enabled after throttle name=server-test rate=5250=== CONT TestConvertHashToNix32/invalid_format2512026/09/21 12:56:11 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:46569252=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths253=== CONT TestEncodeNixBase32/test_string_hash254=== CONT TestEncodeNixBase32/empty_input255--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)256=== CONT TestConvertHashToNix32/SRI_format_to_Nix32257--- PASS: TestEncodeNixBase32 (0.01s)258 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)259 --- PASS: TestEncodeNixBase32/empty_input (0.00s)260=== RUN TestSetClientTLS/rejects_connection_without_client_cert261=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert262=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA263=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA264=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== RUN TestSetClientTLS/preserves_debug_logging_transport266=== CONT TestConvertHashToNix32/already_Nix32_format2672026/09/21 12:56:11 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=20002682026/09/21 12:56:11 WARN Rate limiter enabled after throttle name=server-test rate=52692026/09/21 12:56:11 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:379512702026/09/21 12:56:11 WARN Rate limiter backed off name=server-test rate=52712026/09/21 12:56:11 WARN Rate limiter backed off name=server-test rate=5272=== CONT TestFilterOversizedClosures/no_limit_keeps_everything273--- PASS: TestConvertHashToNix32 (0.01s)274 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)275 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)276 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)277=== CONT TestGetStorePathHash/valid_store_path278=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)280=== PAUSE TestSetClientTLSErrors/invalid_ca_file281=== CONT TestSetClientTLSErrors/missing_cert_file282=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error283=== CONT TestSetClientTLSErrors/invalid_ca_file284=== CONT TestSetClientTLSErrors/missing_ca_file285=== CONT TestSetClientTLSErrors/missing_key_file286=== PAUSE TestPartSizeForNAR/1_TiB287=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error288=== PAUSE TestSetClientTLS/preserves_debug_logging_transport289=== CONT TestSetClientTLS/rejects_connection_without_client_cert290=== CONT TestGetStorePathHash/basename_without_hyphen_should_error291=== CONT TestFilterOversizedClosures/all_closures_skipped2922026/09/21 12:56:11 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50293--- PASS: TestPathInfoCACompatibility (0.00s)294 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)295 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)296 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)297 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.01s)298 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)299=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI300=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512301=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon302=== PAUSE TestParsePathInfoJSON/whitespace_only303=== RUN TestPartSizeForNAR/5_TiB_S3_max_object304=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object305=== CONT TestSetClientTLS/preserves_debug_logging_transport306=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA307--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)308 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)309 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.01s)310=== RUN TestParsePathInfoJSON/invalid_JSON311=== PAUSE TestParsePathInfoJSON/invalid_JSON312=== CONT TestParsePathInfoJSON/Nix_format313=== CONT TestParsePathInfoJSON/whitespace_only314=== RUN TestPartSizeForNAR/capped_at_5_GiB315=== PAUSE TestPartSizeForNAR/capped_at_5_GiB316=== CONT TestPartSizeForNAR/5_TiB_S3_max_object317=== CONT TestParsePathInfoJSON/Lix_format318=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts319--- PASS: TestRateLimiterFeedback (0.00s)320 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)321 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)322 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)323 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)324--- PASS: TestFilterOversizedClosures (0.01s)325 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)326 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)327 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)328--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)329 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)330 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)331=== CONT TestParsePathInfoJSON/empty_input332=== CONT TestParsePathInfoJSON/invalid_JSON333=== CONT TestPartSizeForNAR/zero_stays_at_minimum334=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum335=== CONT TestPartSizeForNAR/1_TiB336=== CONT TestPartSizeForNAR/small_stays_at_minimum337=== CONT TestPartSizeForNAR/capped_at_5_GiB338--- PASS: TestGetStorePathHash (0.02s)339 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)340 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)341 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)342 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)343--- PASS: TestPathInfoHashCompatibility (0.03s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)348--- PASS: TestParsePathInfoJSON (0.03s)349 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)350 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)351 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)352 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)353 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)354--- PASS: TestPartSizeForNAR (0.02s)355 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)356 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)357 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)358 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)359 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)360 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)362--- PASS: TestSetClientTLSErrors (0.02s)363 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)364 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)365 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)366 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)367--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)368--- PASS: TestDumpPathSingleFile (0.04s)3692026/09/21 12:56:11 http: TLS handshake error from 127.0.0.1:47122: remote error: tls: bad certificate370--- PASS: TestStreamPushRequestLine (0.04s)371--- PASS: TestSetClientTLS (0.02s)372 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)373 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)374 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)375--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)376--- PASS: TestDumpPathWriterError (0.05s)377--- PASS: TestCaseHackSuffix (0.05s)378--- PASS: TestDumpPathMatchesNix (0.11s)379--- PASS: TestStreamPushBatchesUnderLoad (0.10s)380--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)381PASS382Running server tests...383The files belonging to this database system will be owned by user "nixbld".384This user must also own the server process.385386The database cluster will be initialized with locale "C".387The default database encoding has accordingly been set to "SQL_ASCII".388The default text search configuration will be set to "english".389390Data page checksums are enabled.391392creating directory /build/postgres1901912333/data ... ok393creating subdirectories ... ok394selecting dynamic shared memory implementation ... posix395selecting default "max_connections" ... 100396selecting default "shared_buffers" ... 128MB397selecting default time zone ... UTC398creating configuration files ... ok399running bootstrap script ... ok400performing post-bootstrap initialization ... ok401syncing data to disk ... ok402403initdb: warning: enabling "trust" authentication for local connections404initdb: 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.405406Success. You can now start the database server using:407408 pg_ctl -D /build/postgres1901912333/data -l logfile start409410/build/postgres1901912333:5432 - no response4112026-09-21 12:56:12.907 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4122026-09-21 12:56:12.907 UTC [130] LOG: listening on Unix socket "/build/postgres1901912333/.s.PGSQL.5432"4132026-09-21 12:56:12.913 UTC [137] LOG: database system was shut down at 2026-09-21 12:56:12 UTC4142026-09-21 12:56:12.916 UTC [130] LOG: database system is ready to accept connections415/build/postgres1901912333:5432 - accepting connections416=== RUN TestService_AuthMiddleware417=== PAUSE TestService_AuthMiddleware418=== RUN TestService_AuthMiddleware_MTLSProxyHeader419=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader420=== RUN TestService_AuthMiddleware_MTLSBoundSubjects421=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects422=== RUN TestService_ReadAuthMiddleware423=== PAUSE TestService_ReadAuthMiddleware424=== RUN TestService_AuthMiddleware_OIDC425=== PAUSE TestService_AuthMiddleware_OIDC426=== RUN TestService_RequireScope_OIDC427=== PAUSE TestService_RequireScope_OIDC428=== RUN TestService_ReadScope_PublicByDefault429=== PAUSE TestService_ReadScope_PublicByDefault430=== RUN TestCacheConfigHandler431=== PAUSE TestCacheConfigHandler432=== RUN TestCacheStatsHandler433=== PAUSE TestCacheStatsHandler434=== RUN TestClientCADerivations435=== PAUSE TestClientCADerivations436=== RUN TestClientErrorHandling437=== PAUSE TestClientErrorHandling438=== RUN TestClientIntegration439=== PAUSE TestClientIntegration440=== RUN TestClientMultipleUploads441=== PAUSE TestClientMultipleUploads442=== RUN TestClientWithDependencies443=== PAUSE TestClientWithDependencies444=== RUN TestClientSharedPathCommittedMidPush445=== PAUSE TestClientSharedPathCommittedMidPush446=== RUN TestPinProtectsFromGC447=== PAUSE TestPinProtectsFromGC448=== RUN TestResolveDBConnectionString449=== PAUSE TestResolveDBConnectionString450=== RUN TestLeadElectsOneAndHandsOver451=== PAUSE TestLeadElectsOneAndHandsOver452=== RUN TestLeadEndsOnShutdown453=== PAUSE TestLeadEndsOnShutdown454=== RUN TestGCAdvisoryLockBlocksConcurrentRun4552026-09-21 12:56:13.285 UTC [567] ERROR: relation "goose_db_version" does not exist at character 364562026-09-21 12:56:13.285 UTC [567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4572026/09/21 12:56:13 OK 20241026095416_initial_model.sql (7.73ms)4582026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)4592026/09/21 12:56:13 OK 20251218171726_add_pins.sql (2.21ms)4602026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (2.2ms)4612026/09/21 12:56:13 OK 20260905000000_add_claims.sql (2.45ms)4622026/09/21 12:56:13 OK 20260920000000_drop_claims.sql (1.51ms)4632026/09/21 12:56:13 goose: successfully migrated database to version: 202609200000004642026/09/21 12:56:13 OK 1_commit_pending_closure.sql (1.5ms)4652026/09/21 12:56:13 OK 2_object_stats_trigger.sql (631.15µs)4662026/09/21 12:56:13 goose: up to current file version: 2467--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)468=== RUN TestGCBugBareHashReferences469=== PAUSE TestGCBugBareHashReferences470=== RUN TestGCMetrics471=== PAUSE TestGCMetrics472=== RUN TestGCTaskStore_StartNew473=== PAUSE TestGCTaskStore_StartNew474=== RUN TestGCTaskStore_DeduplicateSameParams475=== PAUSE TestGCTaskStore_DeduplicateSameParams476=== RUN TestGCTaskStore_ConflictDifferentParams477=== PAUSE TestGCTaskStore_ConflictDifferentParams478=== RUN TestGCTaskStore_GetEmpty479=== PAUSE TestGCTaskStore_GetEmpty480=== RUN TestGCTaskStore_GetReturnsLatest481=== PAUSE TestGCTaskStore_GetReturnsLatest482=== RUN TestGCTaskStore_CompletedAllowsNewTask483=== PAUSE TestGCTaskStore_CompletedAllowsNewTask484=== RUN TestGCTaskStore_PhaseUpdates485=== PAUSE TestGCTaskStore_PhaseUpdates486=== RUN TestGCTaskStore_Fail487=== PAUSE TestGCTaskStore_Fail488=== RUN TestGracefulShutdownDrainsInflight489=== PAUSE TestGracefulShutdownDrainsInflight490=== RUN TestService_healthCheckHandler491=== PAUSE TestService_healthCheckHandler492=== RUN TestService_readinessHandler493=== PAUSE TestService_readinessHandler494=== RUN TestGenerateLandingPage495=== PAUSE TestGenerateLandingPage496=== RUN TestCacheConfigHandlerMaxNarSize497=== PAUSE TestCacheConfigHandlerMaxNarSize498=== RUN TestCreatePendingClosureRejectsOversizedNAR499=== PAUSE TestCreatePendingClosureRejectsOversizedNAR500=== RUN TestNARDeduplicationMetadataUploadBug501=== PAUSE TestNARDeduplicationMetadataUploadBug502=== RUN TestMetricsInventory503=== PAUSE TestMetricsInventory504=== RUN TestService_NativeMTLS505=== PAUSE TestService_NativeMTLS506=== RUN TestServerTLSConfig507=== PAUSE TestServerTLSConfig508=== RUN TestMultipartCleanup509=== PAUSE TestMultipartCleanup510=== RUN TestObjectStatsTrigger511=== PAUSE TestObjectStatsTrigger512=== RUN TestOrphanedObjectsGC513=== PAUSE TestOrphanedObjectsGC514=== RUN TestOrphanedObjectsGCStressTest515=== PAUSE TestOrphanedObjectsGCStressTest516=== RUN TestResurrectedObjectNotDeleted517=== PAUSE TestResurrectedObjectNotDeleted518=== RUN TestParseSingleRange519=== PAUSE TestParseSingleRange520=== RUN TestIsValidCachePath521=== PAUSE TestIsValidCachePath522=== RUN TestReadProxyNarinfo523=== PAUSE TestReadProxyNarinfo524=== RUN TestReadProxyNarinfoAlreadyDecompressed525=== PAUSE TestReadProxyNarinfoAlreadyDecompressed526=== RUN TestReadProxyNarStreaming527=== PAUSE TestReadProxyNarStreaming528=== RUN TestReadProxy404529=== PAUSE TestReadProxy404530=== RUN TestReadProxyInvalidPath531=== PAUSE TestReadProxyInvalidPath532=== RUN TestReadProxyHead533=== PAUSE TestReadProxyHead534=== RUN TestReadProxyConditionalGet535=== PAUSE TestReadProxyConditionalGet536=== RUN TestReadProxyRootRedirectsToIndexHTML537=== PAUSE TestReadProxyRootRedirectsToIndexHTML538=== RUN TestReadProxyDisabled539=== PAUSE TestReadProxyDisabled540=== RUN TestReadRedirectNar541=== PAUSE TestReadRedirectNar542=== RUN TestReadRedirectKeepsNarinfoProxied543=== PAUSE TestReadRedirectKeepsNarinfoProxied544=== RUN TestReadProxyRangeRequest545=== PAUSE TestReadProxyRangeRequest546=== RUN TestReadRedirectUsesPublicS3URL547=== PAUSE TestReadRedirectUsesPublicS3URL548=== RUN TestRedundantMultipartUpload549=== PAUSE TestRedundantMultipartUpload550=== RUN TestCompleteMultipartUpload_ErrorButObjectExists551=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists552=== RUN TestCompletedNarNotReofferedAcrossClosures553=== PAUSE TestCompletedNarNotReofferedAcrossClosures554=== RUN TestPresignedUploadRegisteredBeforeCommit555=== PAUSE TestPresignedUploadRegisteredBeforeCommit556=== RUN TestService_Rustfstest557=== PAUSE TestService_Rustfstest558=== RUN TestParseSize559=== PAUSE TestParseSize560=== RUN TestSkippedUploadsHandler561=== PAUSE TestSkippedUploadsHandler562=== RUN TestSystemdListenerNotActivated563--- PASS: TestSystemdListenerNotActivated (0.00s)564=== RUN TestWatchdogBeatsWhenHealthy565--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)566=== RUN TestWatchdogSkipsWhenUnhealthy5672026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5682026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5692026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5702026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/21 12:56:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"577--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)578=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle579=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle580=== RUN TestProxyWriteTimeout581=== PAUSE TestProxyWriteTimeout582=== RUN TestIsValidUploadKey583=== PAUSE TestIsValidUploadKey584=== RUN TestUploadHandlersRejectInvalidKeys585=== PAUSE TestUploadHandlersRejectInvalidKeys586=== RUN TestUploadHandlersRejectOversizedBody587=== PAUSE TestUploadHandlersRejectOversizedBody588=== RUN TestService_cleanupPendingClosuresHandler589=== PAUSE TestService_cleanupPendingClosuresHandler590=== RUN TestService_createPendingClosureHandler591=== PAUSE TestService_createPendingClosureHandler592=== RUN TestService_verifyS3Integrity593=== PAUSE TestService_verifyS3Integrity594=== RUN TestCompleteMultipartUnregistered595=== PAUSE TestCompleteMultipartUnregistered596=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT597=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT598=== CONT TestService_AuthMiddleware599=== CONT TestService_cleanupPendingClosuresHandler600=== CONT TestGCTaskStore_PhaseUpdates601--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)602=== CONT TestGCBugBareHashReferences603=== CONT TestSkippedUploadsHandler604=== CONT TestGCTaskStore_Fail605=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT606=== CONT TestCompleteMultipartUnregistered607=== CONT TestService_NativeMTLS608=== CONT TestService_createPendingClosureHandler609=== CONT TestMetricsInventory6102026/09/21 12:56:13 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000611=== CONT TestNARDeduplicationMetadataUploadBug612=== CONT TestCreatePendingClosureRejectsOversizedNAR613=== CONT TestCacheConfigHandlerMaxNarSize6142026/09/21 12:56:13 INFO Received uploads request method=POST path=/api/pending_closures615=== CONT TestGenerateLandingPage616=== CONT TestPresignedUploadRegisteredBeforeCommit617=== CONT TestService_readinessHandler618=== CONT TestService_healthCheckHandler619=== CONT TestGracefulShutdownDrainsInflight620=== CONT TestReadProxyDisabled6212026/09/21 12:56:13 INFO Starting HTTP server address=127.0.0.1:44361622=== CONT TestUploadHandlersRejectOversizedBody623=== CONT TestUploadHandlersRejectInvalidKeys6242026/09/21 12:56:13 INFO Shutdown signal received, draining in-flight requests timeout=10s625=== CONT TestIsValidUploadKey626=== RUN TestIsValidUploadKey/narinfo627=== CONT TestProxyWriteTimeout628=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle629=== CONT TestService_verifyS3Integrity630--- PASS: TestGCTaskStore_Fail (0.00s)631=== CONT TestParseSize632=== CONT TestService_Rustfstest633=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info634=== CONT TestCompletedNarNotReofferedAcrossClosures635=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info636=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal637=== RUN TestProxyWriteTimeout/narinfo638=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal639=== PAUSE TestProxyWriteTimeout/narinfo640=== PAUSE TestIsValidUploadKey/narinfo641--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)642--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)643--- PASS: TestParseSize (0.00s)644--- PASS: TestGenerateLandingPage (0.00s)645=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key646=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key647=== CONT TestCompleteMultipartUpload_ErrorButObjectExists648=== RUN TestIsValidUploadKey/nar_zst649=== PAUSE TestIsValidUploadKey/nar_zst650=== RUN TestIsValidUploadKey/nar_xz651=== PAUSE TestIsValidUploadKey/nar_xz652=== RUN TestIsValidUploadKey/nar_plain653=== RUN TestProxyWriteTimeout/1_GiB_nar654=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key655=== PAUSE TestIsValidUploadKey/nar_plain656=== RUN TestIsValidUploadKey/listing657=== PAUSE TestProxyWriteTimeout/1_GiB_nar658=== PAUSE TestIsValidUploadKey/listing659=== RUN TestIsValidUploadKey/build_log660=== PAUSE TestIsValidUploadKey/build_log661=== RUN TestIsValidUploadKey/build_log_home-manager_file662=== PAUSE TestIsValidUploadKey/build_log_home-manager_file663=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key664=== RUN TestProxyWriteTimeout/10_GiB_nar665=== PAUSE TestProxyWriteTimeout/10_GiB_nar666=== RUN TestIsValidUploadKey/build_log_plus_in_name667=== PAUSE TestIsValidUploadKey/build_log_plus_in_name668=== CONT TestRedundantMultipartUpload669=== RUN TestProxyWriteTimeout/unknown_size670=== PAUSE TestProxyWriteTimeout/unknown_size671=== RUN TestIsValidUploadKey/build_log_question_mark672=== PAUSE TestIsValidUploadKey/build_log_question_mark673=== RUN TestIsValidUploadKey/build_log_equals674=== PAUSE TestIsValidUploadKey/build_log_equals675=== RUN TestIsValidUploadKey/realisation676=== PAUSE TestIsValidUploadKey/realisation677=== RUN TestIsValidUploadKey/realisation_plus_in_output678=== PAUSE TestIsValidUploadKey/realisation_plus_in_output679=== RUN TestIsValidUploadKey/nix-cache-info680=== PAUSE TestIsValidUploadKey/nix-cache-info681=== CONT TestReadRedirectUsesPublicS3URL682=== RUN TestIsValidUploadKey/index.html683=== PAUSE TestIsValidUploadKey/index.html684=== RUN TestIsValidUploadKey/narinfo_key,_nar_type685=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type686=== RUN TestIsValidUploadKey/nar_key,_narinfo_type687=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type688=== RUN TestIsValidUploadKey/listing_key,_narinfo_type689=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type690=== RUN TestIsValidUploadKey/traversal691=== PAUSE TestIsValidUploadKey/traversal692=== RUN TestIsValidUploadKey/traversal_nar693=== PAUSE TestIsValidUploadKey/traversal_nar694=== RUN TestIsValidUploadKey/absolute695=== PAUSE TestIsValidUploadKey/absolute696=== RUN TestIsValidUploadKey/empty_key697=== PAUSE TestIsValidUploadKey/empty_key698=== RUN TestIsValidUploadKey/unknown_type699=== PAUSE TestIsValidUploadKey/unknown_type700=== CONT TestReadProxyRangeRequest701--- PASS: TestSkippedUploadsHandler (0.06s)702=== CONT TestReadRedirectKeepsNarinfoProxied703--- PASS: TestGracefulShutdownDrainsInflight (0.07s)704=== CONT TestReadRedirectNar705=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts706=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts707=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure708=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure709=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart710=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart711=== CONT TestReadProxyNarinfo7122026-09-21 12:56:13.794 UTC [640] ERROR: relation "goose_db_version" does not exist at character 367132026-09-21 12:56:13.794 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026-09-21 12:56:13.806 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367152026-09-21 12:56:13.806 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7162026-09-21 12:56:13.809 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367172026-09-21 12:56:13.809 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7182026-09-21 12:56:13.820 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367192026-09-21 12:56:13.820 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026-09-21 12:56:13.832 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367212026-09-21 12:56:13.832 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-09-21 12:56:13.834 UTC [645] ERROR: relation "goose_db_version" does not exist at character 367232026-09-21 12:56:13.834 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026/09/21 12:56:13 OK 20241026095416_initial_model.sql (26.24ms)7252026-09-21 12:56:13.848 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367262026-09-21 12:56:13.848 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7272026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (15.07ms)7282026/09/21 12:56:13 OK 20241026095416_initial_model.sql (34.25ms)7292026/09/21 12:56:13 OK 20241026095416_initial_model.sql (35.78ms)7302026/09/21 12:56:13 OK 20241026095416_initial_model.sql (23.41ms)7312026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)7322026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (4.12ms)7332026/09/21 12:56:13 OK 20251218171726_add_pins.sql (10.4ms)7342026/09/21 12:56:13 OK 20241026095416_initial_model.sql (21.47ms)7352026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (3.8ms)7362026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)7372026/09/21 12:56:13 OK 20251218171726_add_pins.sql (7.73ms)7382026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (7.76ms)7392026/09/21 12:56:13 OK 20251218171726_add_pins.sql (10.87ms)7402026/09/21 12:56:13 OK 20251218171726_add_pins.sql (8.96ms)7412026/09/21 12:56:13 OK 20251218171726_add_pins.sql (8.21ms)7422026/09/21 12:56:13 OK 20260905000000_add_claims.sql (5.09ms)7432026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (8.32ms)7442026-09-21 12:56:13.881 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367452026-09-21 12:56:13.881 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7462026/09/21 12:56:13 OK 20241026095416_initial_model.sql (19.52ms)7472026/09/21 12:56:13 OK 20260920000000_drop_claims.sql (3.71ms)7482026/09/21 12:56:13 goose: successfully migrated database to version: 202609200000007492026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)7502026-09-21 12:56:13.892 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367512026-09-21 12:56:13.892 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7522026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (20.21ms)7532026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (18.93ms)7542026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (18.83ms)7552026/09/21 12:56:13 OK 20251218171726_add_pins.sql (14.29ms)7562026/09/21 12:56:13 OK 20241026095416_initial_model.sql (41.61ms)7572026/09/21 12:56:13 OK 1_commit_pending_closure.sql (16.41ms)7582026/09/21 12:56:13 OK 20260905000000_add_claims.sql (18.65ms)7592026/09/21 12:56:13 OK 2_object_stats_trigger.sql (4.48ms)7602026/09/21 12:56:13 goose: up to current file version: 27612026/09/21 12:56:13 OK 20251210153512_drop_unused_gin_index.sql (5.03ms)7622026/09/21 12:56:13 OK 20260905000000_add_claims.sql (10.13ms)7632026/09/21 12:56:13 OK 20260920000000_drop_claims.sql (6.77ms)7642026/09/21 12:56:13 goose: successfully migrated database to version: 202609200000007652026/09/21 12:56:13 OK 20260905000000_add_claims.sql (11.49ms)7662026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (7.81ms)7672026/09/21 12:56:13 OK 20260905000000_add_claims.sql (11.43ms)7682026/09/21 12:56:13 OK 20260920000000_drop_claims.sql (4.96ms)7692026/09/21 12:56:13 goose: successfully migrated database to version: 202609200000007702026/09/21 12:56:13 OK 1_commit_pending_closure.sql (4.31ms)7712026/09/21 12:56:13 OK 20260920000000_drop_claims.sql (4.89ms)7722026/09/21 12:56:13 goose: successfully migrated database to version: 202609200000007732026/09/21 12:56:13 OK 20260920000000_drop_claims.sql (4.51ms)7742026/09/21 12:56:13 goose: successfully migrated database to version: 202609200000007752026/09/21 12:56:13 OK 20260905000000_add_claims.sql (5.18ms)7762026/09/21 12:56:13 OK 2_object_stats_trigger.sql (2.68ms)7772026/09/21 12:56:13 goose: up to current file version: 27782026-09-21 12:56:13.919 UTC [652] ERROR: relation "goose_db_version" does not exist at character 367792026-09-21 12:56:13.919 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026/09/21 12:56:13 OK 1_commit_pending_closure.sql (8.71ms)7812026/09/21 12:56:13 OK 20251218171726_add_pins.sql (15.29ms)7822026-09-21 12:56:13.931 UTC [653] ERROR: relation "goose_db_version" does not exist at character 367832026-09-21 12:56:13.931 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026/09/21 12:56:13 OK 20241026095416_initial_model.sql (34.39ms)7852026/09/21 12:56:13 OK 1_commit_pending_closure.sql (26.04ms)7862026/09/21 12:56:13 OK 1_commit_pending_closure.sql (26.32ms)7872026/09/21 12:56:13 OK 20260920000000_drop_claims.sql (26.61ms)7882026/09/21 12:56:13 goose: successfully migrated database to version: 202609200000007892026/09/21 12:56:13 OK 20260628120000_add_object_size_and_stats.sql (32.17ms)7902026/09/21 12:56:13 OK 20241026095416_initial_model.sql (42.98ms)7912026/09/21 12:56:13 OK 2_object_stats_trigger.sql (32.3ms)7922026/09/21 12:56:13 goose: up to current file version: 27932026-09-21 12:56:13.965 UTC [654] ERROR: relation "goose_db_version" does not exist at character 367942026-09-21 12:56:13.965 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026-09-21 12:56:13.966 UTC [655] ERROR: relation "goose_db_version" does not exist at character 367962026-09-21 12:56:13.966 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026/09/21 12:56:13 OK 2_object_stats_trigger.sql (35.49ms)7982026/09/21 12:56:13 goose: up to current file version: 27992026/09/21 12:56:14 OK 1_commit_pending_closure.sql (67.27ms)8002026/09/21 12:56:14 OK 2_object_stats_trigger.sql (67.83ms)8012026/09/21 12:56:14 goose: up to current file version: 28022026/09/21 12:56:14 OK 20241026095416_initial_model.sql (54.23ms)8032026/09/21 12:56:14 OK 20260905000000_add_claims.sql (54.76ms)8042026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (67.97ms)8052026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (54.72ms)8062026-09-21 12:56:14.018 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368072026-09-21 12:56:14.018 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026-09-21 12:56:14.019 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368092026-09-21 12:56:14.019 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026-09-21 12:56:14.019 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368112026-09-21 12:56:14.019 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026-09-21 12:56:14.020 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368132026-09-21 12:56:14.020 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-09-21 12:56:14.021 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368152026-09-21 12:56:14.021 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026-09-21 12:56:14.023 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368172026-09-21 12:56:14.023 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (29.59ms)8192026/09/21 12:56:14 OK 2_object_stats_trigger.sql (32.02ms)8202026/09/21 12:56:14 goose: up to current file version: 28212026/09/21 12:56:14 OK 20241026095416_initial_model.sql (30.32ms)8222026/09/21 12:56:14 OK 20251218171726_add_pins.sql (31.73ms)8232026/09/21 12:56:14 OK 20251218171726_add_pins.sql (31.43ms)8242026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (33.02ms)8252026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000008262026/09/21 12:56:14 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"827--- PASS: TestService_AuthMiddleware (0.48s)828=== CONT TestReadProxyRootRedirectsToIndexHTML8292026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)8302026/09/21 12:56:14 OK 20251218171726_add_pins.sql (6.23ms)8312026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)8322026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (5.41ms)8332026/09/21 12:56:14 OK 1_commit_pending_closure.sql (5.02ms)8342026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.56ms)8352026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.84ms)8362026/09/21 12:56:14 goose: up to current file version: 28372026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.72ms)8382026/09/21 12:56:14 OK 20251218171726_add_pins.sql (7.52ms)8392026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.49ms)8402026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000008412026-09-21 12:56:14.052 UTC [665] ERROR: relation "goose_db_version" does not exist at character 368422026-09-21 12:56:14.052 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8432026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.06ms)8442026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.44ms)8452026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.35ms)8462026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (7.86ms)8472026-09-21 12:56:14.053 UTC [663] ERROR: relation "goose_db_version" does not exist at character 368482026-09-21 12:56:14.053 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8492026-09-21 12:56:14.053 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368502026-09-21 12:56:14.053 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8512026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.37ms)8522026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.32ms)8532026/09/21 12:56:14 OK 20241026095416_initial_model.sql (12.02ms)8542026/09/21 12:56:14 OK 20241026095416_initial_model.sql (12.07ms)8552026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)8562026-09-21 12:56:14.054 UTC [667] ERROR: relation "goose_db_version" does not exist at character 368572026-09-21 12:56:14.054 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)8592026-09-21 12:56:14.054 UTC [666] ERROR: relation "goose_db_version" does not exist at character 368602026-09-21 12:56:14.054 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8612026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.48ms)8622026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000008632026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)8642026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.25ms)8652026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)8662026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)8672026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)8682026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)8692026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.44ms)8702026/09/21 12:56:14 goose: up to current file version: 28712026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.86ms)8722026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.65ms)8732026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.56ms)8742026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.26ms)8752026/09/21 12:56:14 OK 20260905000000_add_claims.sql (6.17ms)8762026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (7.65ms)8772026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.08ms)8782026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.79ms)8792026/09/21 12:56:14 goose: up to current file version: 28802026/09/21 12:56:14 OK 20241026095416_initial_model.sql (18.46ms)8812026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.61ms)8822026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.97ms)8832026/09/21 12:56:14 OK 20251218171726_add_pins.sql (5.67ms)8842026/09/21 12:56:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8852026/09/21 12:56:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"886--- PASS: TestService_NativeMTLS (0.49s)887=== CONT TestReadProxyConditionalGet8882026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)8892026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.42ms)8902026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000008912026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)8922026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)8932026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.94ms)8942026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)8952026/09/21 12:56:14 OK 20260905000000_add_claims.sql (5.07ms)8962026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)8972026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.2ms)8982026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000008992026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (7.01ms)9002026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (7.13ms)9012026/09/21 12:56:14 OK 1_commit_pending_closure.sql (4.14ms)9022026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.04ms)9032026/09/21 12:56:14 OK 20251218171726_add_pins.sql (5.48ms)9042026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.62ms)9052026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.68ms)9062026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.84ms)9072026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.48ms)9082026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.62ms)9092026/09/21 12:56:14 goose: up to current file version: 29102026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.59ms)9112026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009122026/09/21 12:56:14 OK 20241026095416_initial_model.sql (12.23ms)9132026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.76ms)9142026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009152026/09/21 12:56:14 OK 1_commit_pending_closure.sql (4.65ms)9162026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.58ms)9172026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.36ms)9182026/09/21 12:56:14 OK 20241026095416_initial_model.sql (10.83ms)9192026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.24ms)9202026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009212026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.3ms)9222026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009232026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.46ms)9242026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009252026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.48ms)9262026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)9272026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)9282026/09/21 12:56:14 OK 1_commit_pending_closure.sql (3.32ms)9292026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.89ms)9302026/09/21 12:56:14 goose: up to current file version: 29312026/09/21 12:56:14 OK 20241026095416_initial_model.sql (12.6ms)9322026/09/21 12:56:14 OK 20241026095416_initial_model.sql (13.12ms)9332026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.98ms)9342026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)9352026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)9362026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.53ms)9372026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009382026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.99ms)9392026/09/21 12:56:14 OK 1_commit_pending_closure.sql (3.09ms)9402026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.73ms)9412026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009422026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.78ms)9432026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.65ms)9442026/09/21 12:56:14 goose: up to current file version: 29452026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.24ms)9462026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.24ms)9472026/09/21 12:56:14 goose: up to current file version: 29482026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)9492026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)9502026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.34ms)9512026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.37ms)9522026/09/21 12:56:14 goose: up to current file version: 29532026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.44ms)9542026/09/21 12:56:14 goose: up to current file version: 29552026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.53ms)9562026/09/21 12:56:14 OK 1_commit_pending_closure.sql (3.37ms)9572026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.8ms)9582026/09/21 12:56:14 OK 20260905000000_add_claims.sql (5.06ms)9592026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.93ms)9602026/09/21 12:56:14 goose: up to current file version: 29612026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9622026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.6ms)9632026/09/21 12:56:14 goose: up to current file version: 29642026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.41ms)9652026/09/21 12:56:14 goose: up to current file version: 29662026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.04ms)9672026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.61ms)9682026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)9692026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.65ms)9702026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009712026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)9722026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.97ms)9732026/09/21 12:56:14 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst974--- PASS: TestCompleteMultipartUnregistered (0.52s)975=== CONT TestReadProxyHead9762026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)9772026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.08ms)9782026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.67ms)9792026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.75ms)9802026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.76ms)9812026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.03ms)9822026/09/21 12:56:14 goose: up to current file version: 29832026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.88ms)9842026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.68ms)9852026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.2ms)9862026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009872026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.32ms)9882026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.22ms)9892026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009902026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.11ms)9912026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009922026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.02ms)9932026/09/21 12:56:14 OK 1_commit_pending_closure.sql (1.78ms)9942026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.11ms)9952026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009962026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.5ms)9972026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000009982026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.48ms)9992026/09/21 12:56:14 goose: up to current file version: 210002026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.29ms)10012026/09/21 12:56:14 goose: up to current file version: 210022026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.25ms)10032026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.25ms)10042026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.97ms)10052026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.7ms)10062026/09/21 12:56:14 goose: up to current file version: 210072026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.31ms)10082026/09/21 12:56:14 goose: up to current file version: 210092026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.23ms)10102026/09/21 12:56:14 goose: up to current file version: 210112026/09/21 12:56:14 WARN readiness check failed error="closed pool"1012--- PASS: TestService_readinessHandler (0.53s)1013=== CONT TestReadProxyInvalidPath10142026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures10152026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures10162026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures10172026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures1018--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.59s)1019=== CONT TestReadProxy40410202026-09-21 12:56:14.172 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3610212026-09-21 12:56:14.172 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10222026/09/21 12:56:14 INFO Received cleanup request method=DELETE path=/api/pending_closures10232026-09-21 12:56:14.181 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3610242026-09-21 12:56:14.181 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10252026/09/21 12:56:14 INFO Aborted multipart uploads count=010262026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures10272026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.7ms)10282026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)10292026-09-21 12:56:14.193 UTC [681] ERROR: relation "goose_db_version" does not exist at character 3610302026-09-21 12:56:14.193 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10312026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.98ms)10322026/09/21 12:56:14 OK 20241026095416_initial_model.sql (8.49ms)10332026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)10342026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)10352026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.81ms)10362026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.09ms)10372026/09/21 12:56:14 INFO Received cleanup request method=DELETE path=/api/pending_closures10382026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)10392026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (1.87ms)10402026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000010412026/09/21 12:56:14 INFO Aborted multipart uploads count=110422026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.31ms)10432026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.04ms)10442026/09/21 12:56:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10452026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.36ms)10462026/09/21 12:56:14 goose: up to current file version: 210472026-09-21 12:56:14.208 UTC [649] ERROR: Closure does not exist: id=110482026-09-21 12:56:14.208 UTC [649] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10492026-09-21 12:56:14.208 UTC [649] STATEMENT: -- name: CommitPendingClosure :exec1050 SELECT commit_pending_closure($1::bigint)1051 10522026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.28ms)1053--- PASS: TestService_cleanupPendingClosuresHandler (0.64s)1054=== CONT TestReadProxyNarStreaming10552026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.02ms)10562026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000010572026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)10582026-09-21 12:56:14.211 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3610592026-09-21 12:56:14.211 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.77ms)10612026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.57ms)10622026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.69ms)10632026/09/21 12:56:14 goose: up to current file version: 210642026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)10652026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.69ms)10662026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.4ms)10672026/09/21 12:56:14 goose: successfully migrated database to version: 202609200000001068--- PASS: TestService_healthCheckHandler (0.66s)1069=== CONT TestReadProxyNarinfoAlreadyDecompressed10702026/09/21 12:56:14 OK 1_commit_pending_closure.sql (3.24ms)10712026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.42ms)10722026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.65ms)10732026/09/21 12:56:14 goose: up to current file version: 210742026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)10752026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.44ms)10762026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)10772026/09/21 12:56:14 OK 20260905000000_add_claims.sql (2.6ms)10782026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.46ms)10792026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000010802026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.25ms)10812026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.44ms)10822026/09/21 12:56:14 goose: up to current file version: 210832026-09-21 12:56:14.248 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3610842026-09-21 12:56:14.248 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1085--- PASS: TestReadProxyDisabled (0.68s)1086=== CONT TestClientErrorHandling1087=== RUN TestClientErrorHandling/InvalidStorePath1088=== PAUSE TestClientErrorHandling/InvalidStorePath1089=== RUN TestClientErrorHandling/InvalidAuthToken1090=== PAUSE TestClientErrorHandling/InvalidAuthToken1091=== RUN TestClientErrorHandling/ServerNotAvailable1092=== PAUSE TestClientErrorHandling/ServerNotAvailable1093=== CONT TestLeadEndsOnShutdown10942026/09/21 12:56:14 OK 20241026095416_initial_model.sql (18.04ms)10952026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)10962026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.43ms)10972026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4ms)10982026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures10992026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.36ms)11002026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.3ms)11012026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000011022026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.23ms)11032026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.61ms)11042026/09/21 12:56:14 goose: up to current file version: 211052026-09-21 12:56:14.297 UTC [690] ERROR: relation "goose_db_version" does not exist at character 3611062026-09-21 12:56:14.297 UTC [690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11072026/09/21 12:56:14 OK 20241026095416_initial_model.sql (7.71ms)11082026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)11092026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.41ms)11102026-09-21 12:56:14.316 UTC [691] ERROR: relation "goose_db_version" does not exist at character 3611112026-09-21 12:56:14.316 UTC [691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11122026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)11132026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.05ms)11142026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (1.95ms)11152026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000011162026/09/21 12:56:14 OK 1_commit_pending_closure.sql (1.79ms)11172026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.83ms)11182026/09/21 12:56:14 goose: up to current file version: 211192026/09/21 12:56:14 OK 20241026095416_initial_model.sql (8.21ms)11202026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)11212026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.82ms)11222026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)11232026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures11242026/09/21 12:56:14 OK 20260905000000_add_claims.sql (2.27ms)11252026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (1.6ms)11262026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000011272026/09/21 12:56:14 OK 1_commit_pending_closure.sql (1.73ms)11282026/09/21 12:56:14 OK 2_object_stats_trigger.sql (914.74µs)11292026/09/21 12:56:14 goose: up to current file version: 211302026-09-21 12:56:14.350 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3611312026-09-21 12:56:14.350 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026/09/21 12:56:14 OK 20241026095416_initial_model.sql (7.88ms)1133=== NAME TestNARDeduplicationMetadataUploadBug1134 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3461569955/001/store/06hf45mj5yxrsbhs1h723nl9s1rpqci7-file1.txt11352026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)11362026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.08ms)11372026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)11382026/09/21 12:56:14 OK 20260905000000_add_claims.sql (2.71ms)11392026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (1.58ms)11402026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000011412026/09/21 12:56:14 OK 1_commit_pending_closure.sql (1.45ms)11422026/09/21 12:56:14 OK 2_object_stats_trigger.sql (785.95µs)11432026/09/21 12:56:14 goose: up to current file version: 211442026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1145--- PASS: TestMetricsInventory (0.81s)1146=== CONT TestLeadElectsOneAndHandsOver11472026/09/21 12:56:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODA5MGY4YmMtMTg3NC00NjY2LTkxMjItYWIyYTI4NDIzMDFkLjlhOGNjNjA4LTA2ZGItNGVjMC1iNjQwLTEwMTkyNGJiOWMwNngxNzg5OTk1Mzc0MzUzNDY4NTk211482026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures11492026/09/21 12:56:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODA5MGY4YmMtMTg3NC00NjY2LTkxMjItYWIyYTI4NDIzMDFkLjlhOGNjNjA4LTA2ZGItNGVjMC1iNjQwLTEwMTkyNGJiOWMwNngxNzg5OTk1Mzc0MzUzNDY4NTk2 parts=11150--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.82s)1151=== CONT TestResolveDBConnectionString1152=== RUN TestResolveDBConnectionString/flag_wins1153=== PAUSE TestResolveDBConnectionString/flag_wins1154=== RUN TestResolveDBConnectionString/file_when_flag_empty1155=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1156=== RUN TestResolveDBConnectionString/missing_file_is_an_error1157=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1158=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1159=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1160=== RUN TestResolveDBConnectionString/nothing_configured1161=== PAUSE TestResolveDBConnectionString/nothing_configured1162=== CONT TestPinProtectsFromGC11632026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/21 12:56:14 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11652026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures11662026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures1167--- PASS: TestGCBugBareHashReferences (0.88s)1168=== CONT TestClientSharedPathCommittedMidPush1169--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.87s)1170=== CONT TestClientWithDependencies11712026/09/21 12:56:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11722026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures11732026-09-21 12:56:14.473 UTC [755] ERROR: relation "goose_db_version" does not exist at character 3611742026-09-21 12:56:14.473 UTC [755] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1175--- PASS: TestService_Rustfstest (0.90s)1176=== CONT TestClientMultipleUploads11772026-09-21 12:56:14.478 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3611782026-09-21 12:56:14.478 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11792026/09/21 12:56:14 OK 20241026095416_initial_model.sql (10.12ms)11802026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11812026/09/21 12:56:14 OK 20241026095416_initial_model.sql (8.75ms)11822026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)11832026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)11842026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures11852026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.5ms)11862026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.89ms)11872026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)11882026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)11892026/09/21 12:56:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11902026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.19ms)11912026/09/21 12:56:14 INFO Uploading 06hf45mj5yxrsbhs1h723nl9s1rpqci7-file1.txt (160B)11922026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.71ms)11932026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.12ms)11942026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000011952026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.09ms)11962026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000011972026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.28ms)11982026/09/21 12:56:14 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11992026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.09ms)12002026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.34ms)12012026/09/21 12:56:14 goose: up to current file version: 212022026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.58ms)12032026/09/21 12:56:14 goose: up to current file version: 212042026/09/21 12:56:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12052026/09/21 12:56:14 WARN Failed to register uploaded object key=06hf45mj5yxrsbhs1h723nl9s1rpqci7.ls error="server returned 404: 404 page not found\n"12062026/09/21 12:56:14 INFO Signed narinfos id=1 count=112072026/09/21 12:56:14 INFO Uploading 1 narinfos1208--- PASS: TestReadProxyRangeRequest (0.89s)1209=== CONT TestClientIntegration12102026/09/21 12:56:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12112026/09/21 12:56:14 WARN Failed to register uploaded object key=06hf45mj5yxrsbhs1h723nl9s1rpqci7.narinfo error="server returned 404: 404 page not found\n"12122026/09/21 12:56:14 INFO Completed upload id=112132026/09/21 12:56:14 INFO Upload complete. (118ms)1214=== NAME TestNARDeduplicationMetadataUploadBug1215 metadata_upload_test.go:54: Retrieved narinfo from S3:1216 StorePath: /build/TestNARDeduplicationMetadataUploadBug3461569955/001/store/06hf45mj5yxrsbhs1h723nl9s1rpqci7-file1.txt1217 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1218 Compression: zstd1219 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1220 NarSize: 1601221 References: 1222 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1223 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1224 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1225 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1226--- PASS: TestReadRedirectUsesPublicS3URL (0.91s)1227=== CONT TestOrphanedObjectsGCStressTest12282026-09-21 12:56:14.544 UTC [779] ERROR: relation "goose_db_version" does not exist at character 3612292026-09-21 12:56:14.544 UTC [779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12302026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.63ms)12312026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1232--- PASS: TestReadRedirectNar (0.93s)12332026-09-21 12:56:14.570 UTC [784] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-21 12:56:14.570 UTC [784] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1235=== CONT TestIsValidCachePath1236=== RUN TestIsValidCachePath/narinfo1237=== PAUSE TestIsValidCachePath/narinfo1238=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1239=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1240=== RUN TestIsValidCachePath/nar_zst1241=== PAUSE TestIsValidCachePath/nar_zst1242=== RUN TestIsValidCachePath/nar_xz12432026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)1244=== PAUSE TestIsValidCachePath/nar_xz1245=== RUN TestIsValidCachePath/nar_bz21246=== PAUSE TestIsValidCachePath/nar_bz21247=== RUN TestIsValidCachePath/nar_uncompressed1248=== PAUSE TestIsValidCachePath/nar_uncompressed1249=== RUN TestIsValidCachePath/ls1250=== PAUSE TestIsValidCachePath/ls1251=== RUN TestIsValidCachePath/log1252=== PAUSE TestIsValidCachePath/log1253=== RUN TestIsValidCachePath/realisation1254=== PAUSE TestIsValidCachePath/realisation1255=== RUN TestIsValidCachePath/nix-cache-info1256=== PAUSE TestIsValidCachePath/nix-cache-info1257=== RUN TestIsValidCachePath/index.html1258=== PAUSE TestIsValidCachePath/index.html1259=== RUN TestIsValidCachePath/traversal_parent1260=== PAUSE TestIsValidCachePath/traversal_parent1261=== RUN TestIsValidCachePath/traversal_in_middle1262=== PAUSE TestIsValidCachePath/traversal_in_middle1263=== RUN TestIsValidCachePath/invalid_char_e1264=== PAUSE TestIsValidCachePath/invalid_char_e1265=== RUN TestIsValidCachePath/invalid_char_u1266=== PAUSE TestIsValidCachePath/invalid_char_u12672026-09-21 12:56:14.573 UTC [782] ERROR: relation "goose_db_version" does not exist at character 3612682026-09-21 12:56:14.573 UTC [782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1269=== RUN TestIsValidCachePath/random_path1270=== PAUSE TestIsValidCachePath/random_path1271=== RUN TestIsValidCachePath/empty1272=== PAUSE TestIsValidCachePath/empty1273=== RUN TestIsValidCachePath/leading_slash1274=== PAUSE TestIsValidCachePath/leading_slash1275=== RUN TestIsValidCachePath/wrong_extension1276=== PAUSE TestIsValidCachePath/wrong_extension12772026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.81ms)1278=== RUN TestIsValidCachePath/short_hash1279=== PAUSE TestIsValidCachePath/short_hash1280=== CONT TestParseSingleRange1281=== RUN TestParseSingleRange/none1282=== PAUSE TestParseSingleRange/none1283=== RUN TestParseSingleRange/unknown_unit1284=== PAUSE TestParseSingleRange/unknown_unit1285=== RUN TestParseSingleRange/multi-range_ignored1286=== PAUSE TestParseSingleRange/multi-range_ignored1287=== RUN TestParseSingleRange/malformed_no_dash1288=== PAUSE TestParseSingleRange/malformed_no_dash1289=== RUN TestParseSingleRange/malformed_both_empty1290=== PAUSE TestParseSingleRange/malformed_both_empty1291=== RUN TestParseSingleRange/malformed_end_before_start1292=== PAUSE TestParseSingleRange/malformed_end_before_start1293=== RUN TestParseSingleRange/closed1294=== PAUSE TestParseSingleRange/closed1295=== RUN TestParseSingleRange/open-ended1296=== PAUSE TestParseSingleRange/open-ended1297=== RUN TestParseSingleRange/end_clamped_to_size1298=== PAUSE TestParseSingleRange/end_clamped_to_size1299=== RUN TestParseSingleRange/suffix1300=== PAUSE TestParseSingleRange/suffix1301=== RUN TestParseSingleRange/suffix_exceeds_size1302=== PAUSE TestParseSingleRange/suffix_exceeds_size1303=== RUN TestParseSingleRange/single_byte1304=== NAME TestNARDeduplicationMetadataUploadBug1305 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3461569955/001/store/sab2957pv244svggjn7k0nyc360c173v-file2.txt1306=== PAUSE TestParseSingleRange/single_byte1307=== RUN TestParseSingleRange/start_past_EOF1308=== PAUSE TestParseSingleRange/start_past_EOF1309=== RUN TestParseSingleRange/start_far_past_EOF1310=== PAUSE TestParseSingleRange/start_far_past_EOF1311=== CONT TestResurrectedObjectNotDeleted13122026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)13132026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.84ms)13142026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures13152026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.59ms)13162026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000013172026/09/21 12:56:14 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODA5MGY4YmMtMTg3NC00NjY2LTkxMjItYWIyYTI4NDIzMDFkLjQ5N2I1YzUzLTQxNTEtNGQ4Mi05NDA4LTgyNTM1NTRmZjE5MHgxNzg5OTk1Mzc0MTYwNDc2OTA2 parts=1013182026/09/21 12:56:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13192026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.12ms)13202026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.51ms)13212026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.6ms)13222026/09/21 12:56:14 goose: up to current file version: 213232026/09/21 12:56:14 INFO Completed upload id=113242026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)13252026/09/21 12:56:14 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013262026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/21 12:56:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures13282026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.55ms)13292026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)13302026/09/21 12:56:14 OK 20241026095416_initial_model.sql (15.66ms)13312026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)13322026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.44ms)13332026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.57ms)13342026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000013352026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.91ms)13362026/09/21 12:56:14 INFO Aborted multipart uploads count=013372026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.42ms)13382026-09-21 12:56:14.609 UTC [820] ERROR: relation "goose_db_version" does not exist at character 3613392026-09-21 12:56:14.609 UTC [820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13402026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.07ms)13412026/09/21 12:56:14 goose: up to current file version: 213422026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (5.17ms)13432026/09/21 12:56:14 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=013442026/09/21 12:56:14 OK 20260905000000_add_claims.sql (5.47ms)13452026/09/21 12:56:14 INFO Vacuumed table table=pending_closures13462026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.81ms)13472026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000013482026/09/21 12:56:14 INFO Vacuumed table table=pending_objects13492026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.3ms)13502026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.76ms)1351--- PASS: TestReadRedirectKeepsNarinfoProxied (0.99s)1352=== CONT TestGCTaskStore_ConflictDifferentParams1353--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1354=== CONT TestGCTaskStore_CompletedAllowsNewTask1355--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1356=== CONT TestGCTaskStore_GetReturnsLatest1357--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1358=== CONT TestGCTaskStore_GetEmpty1359--- PASS: TestGCTaskStore_GetEmpty (0.00s)1360=== CONT TestObjectStatsTrigger13612026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)13622026/09/21 12:56:14 INFO Vacuumed table table=multipart_uploads13632026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.59ms)13642026/09/21 12:56:14 goose: up to current file version: 213652026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.48ms)13662026/09/21 12:56:14 INFO Vacuumed table table=closures13672026/09/21 12:56:14 INFO Vacuumed table table=objects13682026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)13692026/09/21 12:56:14 OK 20260905000000_add_claims.sql (2.94ms)13702026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.49ms)13712026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000013722026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.42ms)13732026/09/21 12:56:14 OK 2_object_stats_trigger.sql (655.46µs)13742026/09/21 12:56:14 goose: up to current file version: 213752026-09-21 12:56:14.644 UTC [842] ERROR: relation "goose_db_version" does not exist at character 3613762026-09-21 12:56:14.644 UTC [842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13772026/09/21 12:56:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001378--- PASS: TestService_createPendingClosureHandler (1.08s)1379=== CONT TestOrphanedObjectsGC1380--- PASS: TestReadProxyNarinfo (0.95s)1381=== CONT TestGCMetrics13822026/09/21 12:56:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13832026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.86ms)13842026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)1385--- PASS: TestReadProxyConditionalGet (0.60s)1386=== CONT TestMultipartCleanup13872026/09/21 12:56:14 OK 20251218171726_add_pins.sql (5.31ms)13882026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (18.81ms)13892026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures1390--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.65s)1391=== CONT TestService_RequireScope_OIDC13922026/09/21 12:56:14 OK 20260905000000_add_claims.sql (7.24ms)13932026/09/21 12:56:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13942026/09/21 12:56:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35717/oidc13952026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.68ms)13962026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000013972026/09/21 12:56:14 WARN Failed to register uploaded object key=sab2957pv244svggjn7k0nyc360c173v.ls error="server returned 404: 404 page not found\n"13982026/09/21 12:56:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13992026/09/21 12:56:14 INFO Signed narinfos id=2 count=114002026/09/21 12:56:14 INFO Uploading 1 narinfos14012026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.65ms)14022026-09-21 12:56:14.704 UTC [884] ERROR: relation "goose_db_version" does not exist at character 3614032026-09-21 12:56:14.704 UTC [884] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14042026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.6ms)14052026/09/21 12:56:14 goose: up to current file version: 214062026/09/21 12:56:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14072026/09/21 12:56:14 WARN Failed to register uploaded object key=sab2957pv244svggjn7k0nyc360c173v.narinfo error="server returned 404: 404 page not found\n"14082026/09/21 12:56:14 INFO Completed upload id=214092026/09/21 12:56:14 INFO Upload complete. (101ms)1410=== NAME TestNARDeduplicationMetadataUploadBug1411 metadata_upload_test.go:76: Retrieved narinfo from S3:1412 StorePath: /build/TestNARDeduplicationMetadataUploadBug3461569955/001/store/sab2957pv244svggjn7k0nyc360c173v-file2.txt1413 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1414 Compression: zstd1415 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1416 NarSize: 1601417 References: 1418 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1419 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1420 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1421 {"version":1,"root":{"type":"regular","size":44}}1422--- PASS: TestReadProxyHead (0.63s)1423=== CONT TestClientCADerivations1424--- PASS: TestNARDeduplicationMetadataUploadBug (1.15s)1425=== CONT TestCacheStatsHandler14262026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.74ms)14272026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)14282026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.02ms)14292026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14302026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)14312026-09-21 12:56:14.737 UTC [890] ERROR: relation "goose_db_version" does not exist at character 3614322026-09-21 12:56:14.737 UTC [890] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1433--- PASS: TestReadProxyInvalidPath (0.64s)1434=== CONT TestCacheConfigHandler1435=== RUN TestCacheConfigHandler/full_config,_no_issuer1436=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1437=== RUN TestCacheConfigHandler/no_cache_url_configured1438=== PAUSE TestCacheConfigHandler/no_cache_url_configured1439=== RUN TestCacheConfigHandler/no_signing_keys1440=== PAUSE TestCacheConfigHandler/no_signing_keys1441=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1442=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1443=== CONT TestService_ReadScope_PublicByDefault14442026/09/21 12:56:14 OK 20260905000000_add_claims.sql (4.86ms)14452026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.19ms)14462026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000014472026/09/21 12:56:14 OK 1_commit_pending_closure.sql (17.32ms)14482026/09/21 12:56:14 OK 2_object_stats_trigger.sql (4.71ms)14492026/09/21 12:56:14 goose: up to current file version: 214502026/09/21 12:56:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODA5MGY4YmMtMTg3NC00NjY2LTkxMjItYWIyYTI4NDIzMDFkLmZmODAzN2VjLTk4MzUtNDRhYy04YmE1LTFhNmQwYTBiMGE3NngxNzg5OTk1Mzc0Mjk5NjU1ODc3 parts=1214512026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures14522026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.35ms)14532026-09-21 12:56:14.773 UTC [894] ERROR: relation "goose_db_version" does not exist at character 3614542026-09-21 12:56:14.773 UTC [894] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14552026-09-21 12:56:14.773 UTC [893] ERROR: relation "goose_db_version" does not exist at character 3614562026-09-21 12:56:14.773 UTC [893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14572026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (4.13ms)1458--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.20s)14592026-09-21 12:56:14.778 UTC [895] ERROR: relation "goose_db_version" does not exist at character 3614602026-09-21 12:56:14.778 UTC [895] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1461=== CONT TestGCTaskStore_DeduplicateSameParams1462--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1463=== CONT TestServerTLSConfig1464=== RUN TestServerTLSConfig/no_client_CA1465=== PAUSE TestServerTLSConfig/no_client_CA1466=== RUN TestServerTLSConfig/missing_CA_file1467=== PAUSE TestServerTLSConfig/missing_CA_file1468=== RUN TestServerTLSConfig/not_a_PEM_file1469=== PAUSE TestServerTLSConfig/not_a_PEM_file1470=== CONT TestService_ReadAuthMiddleware14712026/09/21 12:56:14 OK 20251218171726_add_pins.sql (6.17ms)1472--- PASS: TestReadProxy404 (0.63s)1473=== CONT TestService_AuthMiddleware_OIDC14742026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (6.3ms)14752026/09/21 12:56:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32971/oidc14762026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.95ms)14772026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.95ms)14782026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)14792026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.18ms)14802026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000014812026/09/21 12:56:14 OK 20241026095416_initial_model.sql (10.91ms)14822026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.57ms)14832026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.15ms)14842026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)14852026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.6ms)14862026/09/21 12:56:14 goose: up to current file version: 214872026/09/21 12:56:14 OK 20241026095416_initial_model.sql (12.3ms)14882026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)14892026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.74ms)14902026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)14912026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.37ms)14922026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.01ms)14932026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)14942026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.21ms)14952026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000014962026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)14972026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.92ms)14982026/09/21 12:56:14 OK 1_commit_pending_closure.sql (3.31ms)14992026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.67ms)15002026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000015012026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.93ms)15022026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.9ms)15032026/09/21 12:56:14 goose: up to current file version: 215042026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.91ms)15052026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000015062026/09/21 12:56:14 OK 1_commit_pending_closure.sql (3.45ms)15072026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.43ms)15082026/09/21 12:56:14 goose: up to current file version: 21509--- PASS: TestReadProxyNarStreaming (0.61s)1510=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15112026-09-21 12:56:14.824 UTC [900] ERROR: relation "goose_db_version" does not exist at character 3615122026-09-21 12:56:14.824 UTC [900] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15132026/09/21 12:56:14 OK 1_commit_pending_closure.sql (12.54ms)15142026/09/21 12:56:14 OK 2_object_stats_trigger.sql (4.23ms)15152026/09/21 12:56:14 goose: up to current file version: 215162026-09-21 12:56:14.844 UTC [903] ERROR: relation "goose_db_version" does not exist at character 3615172026-09-21 12:56:14.844 UTC [903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15182026-09-21 12:56:14.844 UTC [904] ERROR: relation "goose_db_version" does not exist at character 3615192026-09-21 12:56:14.844 UTC [904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15202026/09/21 12:56:14 OK 20241026095416_initial_model.sql (10.44ms)1521--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.62s)1522=== CONT TestService_AuthMiddleware_MTLSProxyHeader15232026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)15242026/09/21 12:56:14 OK 20251218171726_add_pins.sql (4.49ms)15252026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (4.9ms)15262026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.32ms)15272026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.61ms)15282026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)15292026/09/21 12:56:14 OK 20241026095416_initial_model.sql (11.33ms)15302026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (4.03ms)15312026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000015322026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (2ms)15332026/09/21 12:56:14 INFO lead: acquired remote=192.0.2.1:123415342026/09/21 12:56:14 INFO lead: released remote=192.0.2.1:12341535--- PASS: TestLeadEndsOnShutdown (0.61s)1536=== CONT TestGCTaskStore_StartNew1537--- PASS: TestGCTaskStore_StartNew (0.00s)1538=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15392026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.67ms)15402026/09/21 12:56:14 INFO Received uploads request method=POST path=/1541=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15422026/09/21 12:56:14 INFO Received request for more parts method=POST path=/1543=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15442026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/1545=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15462026/09/21 12:56:14 INFO Received uploads request method=POST path=/1547--- PASS: TestUploadHandlersRejectInvalidKeys (0.05s)1548 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1549 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1550 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1551 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1552=== CONT TestProxyWriteTimeout/narinfo1553=== CONT TestProxyWriteTimeout/unknown_size1554=== CONT TestProxyWriteTimeout/10_GiB_nar1555=== CONT TestProxyWriteTimeout/1_GiB_nar1556=== CONT TestIsValidUploadKey/narinfo15572026/09/21 12:56:14 OK 1_commit_pending_closure.sql (3.04ms)1558=== CONT TestIsValidUploadKey/realisation_plus_in_output1559=== CONT TestIsValidUploadKey/realisation1560=== CONT TestIsValidUploadKey/build_log_equals1561=== CONT TestIsValidUploadKey/build_log_question_mark1562=== CONT TestIsValidUploadKey/build_log_plus_in_name1563=== CONT TestIsValidUploadKey/build_log_home-manager_file1564=== CONT TestIsValidUploadKey/build_log1565=== CONT TestIsValidUploadKey/listing1566--- PASS: TestProxyWriteTimeout (0.05s)1567 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1568 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1569 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1570 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1571=== CONT TestIsValidUploadKey/nar_plain1572=== CONT TestIsValidUploadKey/nar_xz1573=== CONT TestIsValidUploadKey/nar_zst1574=== CONT TestIsValidUploadKey/nix-cache-info1575=== CONT TestIsValidUploadKey/traversal1576=== CONT TestIsValidUploadKey/unknown_type1577=== CONT TestIsValidUploadKey/empty_key1578=== CONT TestIsValidUploadKey/absolute1579=== CONT TestIsValidUploadKey/traversal_nar1580=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1581=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1582=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1583=== CONT TestIsValidUploadKey/index.html1584--- PASS: TestIsValidUploadKey (0.06s)1585 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1586 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1587 --- PASS: TestIsValidUploadKey/realisation (0.00s)1588 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1589 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1590 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1591 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1592 --- PASS: TestIsValidUploadKey/build_log (0.00s)1593 --- PASS: TestIsValidUploadKey/listing (0.00s)1594 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1595 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1596 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1597 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1598 --- PASS: TestIsValidUploadKey/traversal (0.00s)1599 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1600 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1601 --- PASS: TestIsValidUploadKey/absolute (0.00s)1602 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1603 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1604 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1605 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1606 --- PASS: TestIsValidUploadKey/index.html (0.00s)16072026-09-21 12:56:14.868 UTC [907] ERROR: relation "goose_db_version" does not exist at character 3616082026-09-21 12:56:14.868 UTC [907] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1609=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16102026/09/21 12:56:14 INFO Received request for more parts method=POST path=/16112026/09/21 12:56:14 OK 20251218171726_add_pins.sql (3.28ms)16122026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.23ms)16132026/09/21 12:56:14 goose: up to current file version: 216142026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)16152026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)16162026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.15ms)16172026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.14ms)16182026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.4ms)16192026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000016202026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.61ms)16212026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000016222026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.77ms)16232026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.26ms)16242026/09/21 12:56:14 goose: up to current file version: 216252026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.22ms)16262026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.67ms)16272026/09/21 12:56:14 goose: up to current file version: 216282026/09/21 12:56:14 OK 20241026095416_initial_model.sql (9.94ms)16292026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)16302026-09-21 12:56:14.886 UTC [908] ERROR: relation "goose_db_version" does not exist at character 3616312026-09-21 12:56:14.886 UTC [908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16322026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.68ms)16332026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16342026/09/21 12:56:14 INFO lead: acquired remote=192.0.2.1:123416352026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)16362026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.21ms)16372026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (1.97ms)16382026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000016392026/09/21 12:56:14 OK 20241026095416_initial_model.sql (8.29ms)16402026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.43ms)16412026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)16422026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.28ms)16432026/09/21 12:56:14 goose: up to current file version: 216442026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.81ms)16452026-09-21 12:56:14.905 UTC [910] ERROR: relation "goose_db_version" does not exist at character 3616462026-09-21 12:56:14.905 UTC [910] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1647=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16482026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/16492026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (18.64ms)16502026/09/21 12:56:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16512026/09/21 12:56:14 OK 20260905000000_add_claims.sql (3.36ms)16522026/09/21 12:56:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODA5MGY4YmMtMTg3NC00NjY2LTkxMjItYWIyYTI4NDIzMDFkLjQyMWQ4ZjVmLWUwNWItNDRiYS1iMzg4LThmZjJkODQ1YjA5OXgxNzg5OTk1Mzc0NDYxMTg0MjI1 parts=121653--- PASS: TestRedundantMultipartUpload (1.30s)1654=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16552026/09/21 12:56:14 INFO Received uploads request method=POST path=/16562026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (3.04ms)16572026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000016582026/09/21 12:56:14 OK 1_commit_pending_closure.sql (1.87ms)16592026/09/21 12:56:14 OK 20241026095416_initial_model.sql (8.25ms)16602026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)16612026/09/21 12:56:14 OK 2_object_stats_trigger.sql (2.23ms)16622026/09/21 12:56:14 goose: up to current file version: 216632026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.23ms)16642026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (2.55ms)16652026-09-21 12:56:14.939 UTC [912] ERROR: relation "goose_db_version" does not exist at character 3616662026-09-21 12:56:14.939 UTC [912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16672026/09/21 12:56:14 OK 20260905000000_add_claims.sql (2.14ms)16682026/09/21 12:56:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODA5MGY4YmMtMTg3NC00NjY2LTkxMjItYWIyYTI4NDIzMDFkLmFkZmNjOTRkLTk1ZjEtNGU5ZC1hYmRlLTBjNzhlZTRlMzNmMXgxNzg5OTk1Mzc0NTk0MjI2OTc5 parts=1016692026/09/21 12:56:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16702026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (1.61ms)16712026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000016722026/09/21 12:56:14 OK 1_commit_pending_closure.sql (1.29ms)16732026/09/21 12:56:14 OK 2_object_stats_trigger.sql (666.14µs)16742026/09/21 12:56:14 goose: up to current file version: 216752026/09/21 12:56:14 INFO Completed upload id=116762026-09-21 12:56:14.946 UTC [914] ERROR: relation "goose_db_version" does not exist at character 3616772026-09-21 12:56:14.946 UTC [914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16782026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures1679=== CONT TestClientErrorHandling/InvalidStorePath16802026/09/21 12:56:14 INFO Received uploads request method=POST path=/api/pending_closures16812026/09/21 12:56:14 OK 20241026095416_initial_model.sql (7.18ms)16822026/09/21 12:56:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16832026/09/21 12:56:14 WARN Found objects in DB but missing from S3, will re-upload count=116842026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (993.29µs)1685--- PASS: TestService_verifyS3Integrity (1.38s)1686=== CONT TestClientErrorHandling/ServerNotAvailable16872026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.26ms)16882026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (2.7ms)16892026/09/21 12:56:14 OK 20241026095416_initial_model.sql (6.99ms)16902026/09/21 12:56:14 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)16912026/09/21 12:56:14 OK 20260905000000_add_claims.sql (2.21ms)16922026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (2.09ms)16932026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000016942026/09/21 12:56:14 OK 20251218171726_add_pins.sql (2.48ms)16952026/09/21 12:56:14 OK 1_commit_pending_closure.sql (2.14ms)16962026/09/21 12:56:14 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)16972026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.83ms)16982026/09/21 12:56:14 goose: up to current file version: 216992026/09/21 12:56:14 OK 20260905000000_add_claims.sql (2.33ms)17002026/09/21 12:56:14 OK 20260920000000_drop_claims.sql (1.54ms)17012026/09/21 12:56:14 goose: successfully migrated database to version: 2026092000000017022026/09/21 12:56:14 OK 1_commit_pending_closure.sql (1.99ms)17032026/09/21 12:56:14 OK 2_object_stats_trigger.sql (1.17ms)17042026/09/21 12:56:14 goose: up to current file version: 21705=== NAME TestClientMultipleUploads1706 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1708686147/001/store/190znm3lnwrzarvpk03phbvqnwxcdcq6-test-file-0.txt1707=== NAME TestPinProtectsFromGC1708 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3391799232/001/store/ric00ciwvif0c4jb0v0bi3xizwm0vikn-pinned-file.txt1709 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3391799232/001/store/934kx22qya3kdcjp83z49n2pzqbyq3cl-unpinned-file.txt17102026-09-21 12:56:15.024 UTC [1043] ERROR: relation "goose_db_version" does not exist at character 3617112026-09-21 12:56:15.024 UTC [1043] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1712=== NAME TestClientMultipleUploads1713 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1708686147/001/store/pmji6bjmsxh3jzds62kpckk6zwihi53q-test-file-1.txt1714=== NAME TestClientWithDependencies1715 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies163499429/001/store/3njyjxsg622hflzqq1lvm77sp2zwdq5b-test-script17162026/09/21 12:56:15 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/present1717=== NAME TestClientIntegration1718 client_integration_test.go:286: Created store path: /build/TestClientIntegration3637155661/002/store/awq0i7dzpx0dac3qigrb4nzdg6v60qkr-test-file.txt17192026/09/21 12:56:15 OK 20241026095416_initial_model.sql (7.59ms)17202026/09/21 12:56:15 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)17212026/09/21 12:56:15 OK 20251218171726_add_pins.sql (2.03ms)17222026/09/21 12:56:15 INFO lead: released remote=192.0.2.1:123417232026/09/21 12:56:15 OK 20260628120000_add_object_size_and_stats.sql (2.38ms)17242026/09/21 12:56:15 OK 20260905000000_add_claims.sql (2.47ms)17252026/09/21 12:56:15 OK 20260920000000_drop_claims.sql (1.48ms)17262026/09/21 12:56:15 goose: successfully migrated database to version: 2026092000000017272026/09/21 12:56:15 OK 1_commit_pending_closure.sql (1.47ms)17282026/09/21 12:56:15 OK 2_object_stats_trigger.sql (716.68µs)17292026/09/21 12:56:15 goose: up to current file version: 21730--- PASS: TestObjectStatsTrigger (0.43s)1731=== CONT TestClientErrorHandling/InvalidAuthToken1732--- PASS: TestResurrectedObjectNotDeleted (0.48s)1733=== CONT TestResolveDBConnectionString/flag_wins1734=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1735=== CONT TestResolveDBConnectionString/nothing_configured1736=== CONT TestResolveDBConnectionString/missing_file_is_an_error1737=== CONT TestResolveDBConnectionString/file_when_flag_empty1738=== CONT TestIsValidCachePath/narinfo1739=== CONT TestIsValidCachePath/index.html1740=== CONT TestIsValidCachePath/short_hash1741=== CONT TestIsValidCachePath/wrong_extension1742=== CONT TestIsValidCachePath/leading_slash1743=== CONT TestIsValidCachePath/empty1744=== CONT TestIsValidCachePath/random_path1745=== CONT TestIsValidCachePath/invalid_char_u1746=== CONT TestIsValidCachePath/invalid_char_e1747=== CONT TestIsValidCachePath/traversal_in_middle1748=== CONT TestIsValidCachePath/traversal_parent1749=== CONT TestIsValidCachePath/nar_uncompressed1750=== CONT TestIsValidCachePath/nix-cache-info1751=== CONT TestIsValidCachePath/realisation1752=== CONT TestIsValidCachePath/log1753=== CONT TestIsValidCachePath/ls1754=== CONT TestIsValidCachePath/nar_xz1755=== CONT TestIsValidCachePath/nar_bz21756=== CONT TestIsValidCachePath/nar_zst1757=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1758--- PASS: TestIsValidCachePath (0.00s)1759 --- PASS: TestIsValidCachePath/narinfo (0.00s)1760 --- PASS: TestIsValidCachePath/index.html (0.00s)1761 --- PASS: TestIsValidCachePath/short_hash (0.00s)1762 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1763 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1764 --- PASS: TestIsValidCachePath/empty (0.00s)1765 --- PASS: TestIsValidCachePath/random_path (0.00s)1766 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1767 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1768 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1769 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1770 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1771 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1772 --- PASS: TestIsValidCachePath/realisation (0.00s)1773 --- PASS: TestIsValidCachePath/log (0.00s)1774 --- PASS: TestIsValidCachePath/ls (0.00s)1775 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1776 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1777 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1778 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1779--- PASS: TestResolveDBConnectionString (0.00s)1780 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1781 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1782 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1783 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1784 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1785=== CONT TestParseSingleRange/none1786=== CONT TestParseSingleRange/open-ended1787=== CONT TestParseSingleRange/start_far_past_EOF1788=== CONT TestParseSingleRange/start_past_EOF1789=== CONT TestParseSingleRange/single_byte1790=== CONT TestParseSingleRange/suffix_exceeds_size1791=== CONT TestParseSingleRange/suffix1792=== CONT TestParseSingleRange/malformed_both_empty1793=== CONT TestParseSingleRange/closed1794=== CONT TestParseSingleRange/malformed_end_before_start1795=== CONT TestParseSingleRange/multi-range_ignored1796=== CONT TestParseSingleRange/malformed_no_dash1797=== CONT TestParseSingleRange/end_clamped_to_size1798=== CONT TestParseSingleRange/unknown_unit1799--- PASS: TestParseSingleRange (0.00s)1800 --- PASS: TestParseSingleRange/none (0.00s)1801 --- PASS: TestParseSingleRange/open-ended (0.00s)1802 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1803 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1804 --- PASS: TestParseSingleRange/single_byte (0.00s)1805 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1806 --- PASS: TestParseSingleRange/suffix (0.00s)1807 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1808 --- PASS: TestParseSingleRange/closed (0.00s)1809 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1810 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1811 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1812 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1813 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1814=== CONT TestCacheConfigHandler/full_config,_no_issuer1815=== CONT TestCacheConfigHandler/no_signing_keys1816=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1817=== CONT TestCacheConfigHandler/no_cache_url_configured1818--- PASS: TestCacheConfigHandler (0.00s)1819 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1820 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1821 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1822 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1823=== CONT TestServerTLSConfig/no_client_CA1824=== CONT TestServerTLSConfig/not_a_PEM_file1825=== CONT TestServerTLSConfig/missing_CA_file1826--- PASS: TestServerTLSConfig (0.00s)1827 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1828 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1829 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1830=== NAME TestClientMultipleUploads1831 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1708686147/001/store/zl0p0ajvz2afc5g299lnynyxfm79ncp8-test-file-2.txt1832=== NAME TestClientWithDependencies1833 client_integration_test.go:615: Found 1 dependencies (including self)18342026/09/21 12:56:15 INFO Aborted multipart uploads count=018352026/09/21 12:56:15 WARN Force mode enabled - objects will be deleted immediately without grace period18362026/09/21 12:56:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018372026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18382026/09/21 12:56:15 INFO Vacuumed table table=pending_closures18392026/09/21 12:56:15 INFO Vacuumed table table=pending_objects18402026/09/21 12:56:15 INFO Vacuumed table table=multipart_uploads18412026/09/21 12:56:15 INFO Vacuumed table table=closures18422026/09/21 12:56:15 INFO Vacuumed table table=objects1843--- PASS: TestGCMetrics (0.43s)18442026/09/21 12:56:15 INFO lead: acquired remote=192.0.2.1:123418452026/09/21 12:56:15 INFO lead: released remote=192.0.2.1:12341846--- PASS: TestLeadElectsOneAndHandsOver (0.71s)18472026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures18482026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures18492026/09/21 12:56:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18502026/09/21 12:56:15 INFO Uploading ric00ciwvif0c4jb0v0bi3xizwm0vikn-pinned-file.txt (128B)18512026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18522026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18532026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18542026/09/21 12:56:15 WARN Failed to register uploaded object key=ric00ciwvif0c4jb0v0bi3xizwm0vikn.ls error="server returned 404: 404 page not found\n"18552026/09/21 12:56:15 INFO Signed narinfos id=1 count=118562026/09/21 12:56:15 INFO Uploading 1 narinfos18572026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18582026/09/21 12:56:15 WARN Failed to register uploaded object key=ric00ciwvif0c4jb0v0bi3xizwm0vikn.narinfo error="server returned 404: 404 page not found\n"18592026-09-21 12:56:15.133 UTC [1293] ERROR: relation "goose_db_version" does not exist at character 3618602026-09-21 12:56:15.133 UTC [1293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18612026/09/21 12:56:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.206109ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18622026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18632026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures18642026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1865=== RUN TestService_RequireScope_OIDC/builder_may_write1866=== PAUSE TestService_RequireScope_OIDC/builder_may_write1867=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1868=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1869=== RUN TestService_RequireScope_OIDC/ops_may_admin1870=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1871=== RUN TestService_RequireScope_OIDC/ops_may_not_write1872=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1873=== RUN TestService_RequireScope_OIDC/reader_may_not_write1874=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1875=== RUN TestService_RequireScope_OIDC/static_token_may_admin1876=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1877=== RUN TestService_RequireScope_OIDC/static_token_may_write1878=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1879=== RUN TestService_RequireScope_OIDC/reader_may_read1880=== PAUSE TestService_RequireScope_OIDC/reader_may_read1881=== RUN TestService_RequireScope_OIDC/writer_implies_read1882=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1883=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1884=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1885=== CONT TestService_RequireScope_OIDC/builder_may_write1886=== CONT TestService_RequireScope_OIDC/static_token_may_admin1887=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1888=== CONT TestService_RequireScope_OIDC/static_token_may_write1889=== CONT TestService_RequireScope_OIDC/ops_may_not_write18902026/09/21 12:56:15 INFO Completed upload id=11891=== CONT TestService_RequireScope_OIDC/writer_implies_read18922026/09/21 12:56:15 INFO Upload complete. (108ms)1893=== CONT TestService_RequireScope_OIDC/reader_may_read18942026/09/21 12:56:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18952026/09/21 12:56:15 INFO Uploading 3njyjxsg622hflzqq1lvm77sp2zwdq5b-test-script (136B)1896=== CONT TestService_RequireScope_OIDC/reader_may_not_write1897=== CONT TestService_RequireScope_OIDC/ops_may_admin18982026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1899=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1900--- PASS: TestService_RequireScope_OIDC (0.45s)1901 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19112026/09/21 12:56:15 WARN Failed to register uploaded object key=log/0mqdbrwp40nn0k1r4d4b94xwf9jzm0nq-test-script.drv error="server returned 404: 404 page not found\n"19122026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19132026/09/21 12:56:15 OK 20241026095416_initial_model.sql (7.92ms)19142026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19152026/09/21 12:56:15 WARN Failed to register uploaded object key=3njyjxsg622hflzqq1lvm77sp2zwdq5b.ls error="server returned 404: 404 page not found\n"19162026/09/21 12:56:15 INFO Signed narinfos id=1 count=119172026/09/21 12:56:15 INFO Uploading 1 narinfos19182026/09/21 12:56:15 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)19192026/09/21 12:56:15 OK 20251218171726_add_pins.sql (2.48ms)19202026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19212026/09/21 12:56:15 WARN Failed to register uploaded object key=3njyjxsg622hflzqq1lvm77sp2zwdq5b.narinfo error="server returned 404: 404 page not found\n"19222026/09/21 12:56:15 OK 20260628120000_add_object_size_and_stats.sql (2.65ms)19232026/09/21 12:56:15 INFO Completed upload id=119242026/09/21 12:56:15 INFO Upload complete. (59ms)19252026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures19262026/09/21 12:56:15 OK 20260905000000_add_claims.sql (2.28ms)1927=== NAME TestClientWithDependencies1928 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies163499429/001/store) requires matching store prefix19292026/09/21 12:56:15 OK 20260920000000_drop_claims.sql (1.64ms)19302026/09/21 12:56:15 goose: successfully migrated database to version: 2026092000000019312026/09/21 12:56:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19322026/09/21 12:56:15 OK 1_commit_pending_closure.sql (1.53ms)19332026/09/21 12:56:15 INFO Uploading awq0i7dzpx0dac3qigrb4nzdg6v60qkr-test-file.txt (152B)19342026/09/21 12:56:15 OK 2_object_stats_trigger.sql (655.32µs)19352026/09/21 12:56:15 goose: up to current file version: 21936--- PASS: TestCacheStatsHandler (0.44s)19372026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1938--- PASS: TestClientWithDependencies (0.72s)19392026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19402026/09/21 12:56:15 INFO Signed narinfos id=1 count=119412026/09/21 12:56:15 WARN Failed to register uploaded object key=awq0i7dzpx0dac3qigrb4nzdg6v60qkr.ls error="server returned 404: 404 page not found\n"19422026/09/21 12:56:15 INFO Uploading 1 narinfos19432026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures19442026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19452026/09/21 12:56:15 WARN Failed to register uploaded object key=awq0i7dzpx0dac3qigrb4nzdg6v60qkr.narinfo error="server returned 404: 404 page not found\n"19462026/09/21 12:56:15 INFO Completed upload id=119472026/09/21 12:56:15 INFO Upload complete. (102ms)1948--- PASS: TestService_ReadScope_PublicByDefault (0.44s)19492026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures19502026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures19512026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures19522026/09/21 12:56:15 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19532026/09/21 12:56:15 INFO Uploading zl0p0ajvz2afc5g299lnynyxfm79ncp8-test-file-2.txt (160B)19542026/09/21 12:56:15 INFO Uploading 190znm3lnwrzarvpk03phbvqnwxcdcq6-test-file-0.txt (160B)19552026/09/21 12:56:15 INFO Uploading pmji6bjmsxh3jzds62kpckk6zwihi53q-test-file-1.txt (160B)19562026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19572026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19582026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19592026/09/21 12:56:15 WARN Failed to register uploaded object key=zl0p0ajvz2afc5g299lnynyxfm79ncp8.ls error="server returned 404: 404 page not found\n"19602026/09/21 12:56:15 WARN Failed to register uploaded object key=pmji6bjmsxh3jzds62kpckk6zwihi53q.ls error="server returned 404: 404 page not found\n"19612026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19622026/09/21 12:56:15 WARN Failed to register uploaded object key=190znm3lnwrzarvpk03phbvqnwxcdcq6.ls error="server returned 404: 404 page not found\n"19632026/09/21 12:56:15 INFO Signed narinfos id=1 count=119642026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19652026/09/21 12:56:15 INFO Signed narinfos id=2 count=119662026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign19672026/09/21 12:56:15 INFO Signed narinfos id=3 count=119682026/09/21 12:56:15 INFO Uploading 3 narinfos1969--- PASS: TestService_ReadAuthMiddleware (0.42s)19702026/09/21 12:56:15 WARN Failed to register uploaded object key=pmji6bjmsxh3jzds62kpckk6zwihi53q.narinfo error="server returned 404: 404 page not found\n"19712026/09/21 12:56:15 WARN Failed to register uploaded object key=190znm3lnwrzarvpk03phbvqnwxcdcq6.narinfo error="server returned 404: 404 page not found\n"19722026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19732026/09/21 12:56:15 WARN Failed to register uploaded object key=zl0p0ajvz2afc5g299lnynyxfm79ncp8.narinfo error="server returned 404: 404 page not found\n"19742026/09/21 12:56:15 INFO Completed upload id=119752026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19762026/09/21 12:56:15 INFO Completed upload id=219772026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete19782026/09/21 12:56:15 INFO Completed upload id=319792026/09/21 12:56:15 INFO Upload complete. (106ms)1980=== NAME TestClientMultipleUploads1981 client_integration_test.go:369: Uploaded 3 paths in 145.171657ms19822026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19832026/09/21 12:56:15 INFO Received cleanup request method=DELETE path=/api/pending_closures1984--- PASS: TestClientMultipleUploads (0.74s)19852026/09/21 12:56:15 INFO All 1 paths already cached1986=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1987=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1988=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1989=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1990=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1991=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1992=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1993=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1994=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1995=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1996=== NAME TestClientIntegration1997 client_integration_test.go:312: Retrieved narinfo from S3:19982026/09/21 12:56:15 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]1999 StorePath: /build/TestClientIntegration3637155661/002/store/awq0i7dzpx0dac3qigrb4nzdg6v60qkr-test-file.txt2000 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2001 Compression: zstd2002 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12003 NarSize: 1522004 References: 2005 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12006=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2007=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2008=== NAME TestClientIntegration20092026/09/21 12:56:15 INFO Aborted multipart uploads count=12010 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)20112026/09/21 12:56:15 WARN Authentication failed token_preview=eyJhbGciOi...59cy8s0_-g token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2012 client_integration_test.go:313: Decompressed .ls content (64 bytes):2013 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2014 client_integration_test.go:316: Testing garbage collection...2015--- PASS: TestService_AuthMiddleware_OIDC (0.43s)2016 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2017 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2018 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2019 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2020--- PASS: TestMultipartCleanup (0.56s)2021=== NAME TestClientCADerivations2022 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3842711088/001/store/vzy2bmpnzycxhzn4mgv33qdbx35viy2m-ca-test20232026/09/21 12:56:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20242026/09/21 12:56:15 WARN mTLS auth: bound subjects configured but subject DN unavailable20252026/09/21 12:56:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2026--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.41s)20272026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20282026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures20292026/09/21 12:56:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures20302026/09/21 12:56:15 INFO Garbage collection started20312026/09/21 12:56:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20322026/09/21 12:56:15 INFO Uploading 934kx22qya3kdcjp83z49n2pzqbyq3cl-unpinned-file.txt (128B)20332026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"2034--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.41s)20352026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20362026/09/21 12:56:15 INFO Signed narinfos id=2 count=120372026/09/21 12:56:15 WARN Failed to register uploaded object key=934kx22qya3kdcjp83z49n2pzqbyq3cl.ls error="server returned 404: 404 page not found\n"20382026/09/21 12:56:15 INFO Uploading 1 narinfos20392026/09/21 12:56:15 INFO Aborted multipart uploads count=020402026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20412026/09/21 12:56:15 WARN Failed to register uploaded object key=934kx22qya3kdcjp83z49n2pzqbyq3cl.narinfo error="server returned 404: 404 page not found\n"20422026/09/21 12:56:15 WARN Force mode enabled - objects will be deleted immediately without grace period2043=== NAME TestClientCADerivations2044 client_ca_test.go:139: Found 1 dependencies (including self)20452026/09/21 12:56:15 INFO Completed upload id=220462026/09/21 12:56:15 INFO Upload complete. (90ms)20472026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures20482026/09/21 12:56:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20492026/09/21 12:56:15 INFO Uploading a9qmxla04qhainvz2pqdqaxh7cji9wvi-shared-dep (136B)20502026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20512026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20522026/09/21 12:56:15 WARN Failed to register uploaded object key=a9qmxla04qhainvz2pqdqaxh7cji9wvi.ls error="server returned 404: 404 page not found\n"20532026/09/21 12:56:15 INFO Signed narinfos id=2 count=120542026/09/21 12:56:15 INFO Uploading 1 narinfos20552026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20562026/09/21 12:56:15 WARN Failed to register uploaded object key=a9qmxla04qhainvz2pqdqaxh7cji9wvi.narinfo error="server returned 404: 404 page not found\n"20572026/09/21 12:56:15 INFO Received create pin request method=POST path=/api/pins/myapp20582026/09/21 12:56:15 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3391799232/001/store/ric00ciwvif0c4jb0v0bi3xizwm0vikn-pinned-file.txt narinfo_key=ric00ciwvif0c4jb0v0bi3xizwm0vikn.narinfo20592026/09/21 12:56:15 INFO Completed upload id=220602026/09/21 12:56:15 INFO Upload complete. (93ms)20612026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures20622026/09/21 12:56:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures20632026/09/21 12:56:15 INFO Garbage collection started20642026/09/21 12:56:15 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20652026/09/21 12:56:15 INFO Uploading hgspph2pcw8v9falsw7rpcq5m7gxv6x1-top (224B)20662026/09/21 12:56:15 INFO Uploading a9qmxla04qhainvz2pqdqaxh7cji9wvi-shared-dep (136B)20672026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/0vfqwjfndx9yvrwympdk3zipghbkp8fpikdr9dpriv46h2l4zh81.nar.zst error="server returned 404: 404 page not found\n"20682026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20692026/09/21 12:56:15 WARN Failed to register uploaded object key=a9qmxla04qhainvz2pqdqaxh7cji9wvi.ls error="server returned 404: 404 page not found\n"20702026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20712026/09/21 12:56:15 WARN Failed to register uploaded object key=hgspph2pcw8v9falsw7rpcq5m7gxv6x1.ls error="server returned 404: 404 page not found\n"20722026/09/21 12:56:15 INFO Signed narinfos id=1 count=120732026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20742026/09/21 12:56:15 INFO Aborted multipart uploads count=020752026/09/21 12:56:15 INFO Signed narinfos id=3 count=120762026/09/21 12:56:15 INFO Uploading 2 narinfos20772026/09/21 12:56:15 WARN Force mode enabled - objects will be deleted immediately without grace period20782026/09/21 12:56:15 WARN Failed to register uploaded object key=hgspph2pcw8v9falsw7rpcq5m7gxv6x1.narinfo error="server returned 404: 404 page not found\n"20792026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20802026/09/21 12:56:15 WARN Failed to register uploaded object key=a9qmxla04qhainvz2pqdqaxh7cji9wvi.narinfo error="server returned 404: 404 page not found\n"20812026/09/21 12:56:15 INFO Completed upload id=120822026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20832026/09/21 12:56:15 INFO Completed upload id=320842026/09/21 12:56:15 INFO Upload complete. (232ms)2085=== NAME TestClientSharedPathCommittedMidPush2086 client_integration_test.go:680: Retrieved narinfo from S3:2087 StorePath: /build/TestClientSharedPathCommittedMidPush1945659394/001/store/a9qmxla04qhainvz2pqdqaxh7cji9wvi-shared-dep2088 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2089 Compression: zstd2090 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822091 NarSize: 1362092 References: 2093 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2094 client_integration_test.go:680: Retrieved narinfo from S3:2095 StorePath: /build/TestClientSharedPathCommittedMidPush1945659394/001/store/hgspph2pcw8v9falsw7rpcq5m7gxv6x1-top2096 URL: nar/0vfqwjfndx9yvrwympdk3zipghbkp8fpikdr9dpriv46h2l4zh81.nar.zst2097 Compression: zstd2098 NarHash: sha256:0vfqwjfndx9yvrwympdk3zipghbkp8fpikdr9dpriv46h2l4zh812099 NarSize: 2242100 References: /build/TestClientSharedPathCommittedMidPush1945659394/001/store/a9qmxla04qhainvz2pqdqaxh7cji9wvi-shared-dep2101 CA: text:sha256:1j566vvqhalx5cz82sjllfcj7c8w3m4cl2r59xzsw7dcp70v41j621022026/09/21 12:56:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.338656ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2103--- PASS: TestClientSharedPathCommittedMidPush (0.89s)21042026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21052026/09/21 12:56:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21062026/09/21 12:56:15 INFO Received uploads request method=POST path=/api/pending_closures21072026/09/21 12:56:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21082026/09/21 12:56:15 INFO Uploading vzy2bmpnzycxhzn4mgv33qdbx35viy2m-ca-test (144B)21092026/09/21 12:56:15 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21102026/09/21 12:56:15 WARN Failed to register uploaded object key=log/8r6b4y61863d5jxirc4igfjb8xx5shwn-ca-test.drv error="server returned 404: 404 page not found\n"2111=== NAME TestOrphanedObjectsGC2112 orphaned_objects_gc_test.go:290: GC Test Summary:2113 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2114 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2115 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2116 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2117 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2118--- PASS: TestOrphanedObjectsGC (0.75s)21192026/09/21 12:56:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21202026/09/21 12:56:15 WARN Failed to register uploaded object key=vzy2bmpnzycxhzn4mgv33qdbx35viy2m.ls error="server returned 404: 404 page not found\n"21212026/09/21 12:56:15 INFO Signed narinfos id=1 count=121222026/09/21 12:56:15 INFO Uploading 1 narinfos21232026/09/21 12:56:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21242026/09/21 12:56:15 WARN Failed to register uploaded object key=vzy2bmpnzycxhzn4mgv33qdbx35viy2m.narinfo error="server returned 404: 404 page not found\n"21252026/09/21 12:56:15 INFO Completed upload id=121262026/09/21 12:56:15 INFO Upload complete. (99ms)2127=== NAME TestClientCADerivations2128 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3842711088/001/store/vzy2bmpnzycxhzn4mgv33qdbx35viy2m-ca-test2129 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2130 Compression: zstd2131 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2132 NarSize: 1442133 References: 2134 Deriver: /build/TestClientCADerivations3842711088/001/store/8r6b4y61863d5jxirc4igfjb8xx5shwn-ca-test.drv2135 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2136 client_ca_test.go:185: Checking for realisation files in S3...2137 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2138 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21392026/09/21 12:56:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21402026/09/21 12:56:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2141--- PASS: TestUploadHandlersRejectOversizedBody (0.13s)2142 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2143 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2144 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.62s)2145=== NAME TestClientCADerivations2146 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2147 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2148 error: binary cache 's3://bucket47?endpoint=http://localhost:46077®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3842711088/001/store'2149 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12150--- PASS: TestClientCADerivations (0.83s)21512026/09/21 12:56:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.686728ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21522026/09/21 12:56:16 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=021532026/09/21 12:56:16 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=021542026/09/21 12:56:16 INFO Vacuumed table table=pending_closures21552026/09/21 12:56:16 INFO Vacuumed table table=pending_closures21562026/09/21 12:56:16 INFO Vacuumed table table=pending_objects21572026/09/21 12:56:16 INFO Vacuumed table table=multipart_uploads21582026/09/21 12:56:16 INFO Vacuumed table table=pending_objects21592026/09/21 12:56:16 INFO Vacuumed table table=multipart_uploads21602026/09/21 12:56:16 INFO Vacuumed table table=closures21612026/09/21 12:56:16 INFO Vacuumed table table=closures21622026/09/21 12:56:16 INFO Vacuumed table table=objects21632026/09/21 12:56:16 INFO Vacuumed table table=objects2164=== NAME TestOrphanedObjectsGCStressTest2165 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2166 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21672026/09/21 12:56:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.564928234s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2168 orphaned_objects_gc_test.go:509: Stress test completed successfully:2169 orphaned_objects_gc_test.go:510: - Active objects preserved: 202170 orphaned_objects_gc_test.go:511: - Objects deleted: 2102171 orphaned_objects_gc_test.go:512: - Total GC'd: 2102172--- PASS: TestOrphanedObjectsGCStressTest (2.25s)21732026/09/21 12:56:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02174=== NAME TestClientIntegration2175 client_integration_test.go:323: Objects in database after GC:2176 client_integration_test.go:323: Successfully deleted all objects with GC --force2177--- PASS: TestClientIntegration (2.74s)21782026/09/21 12:56:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02179=== NAME TestPinProtectsFromGC2180 client_integration_test.go:794: Pin successfully protected closure from garbage collection2181--- PASS: TestPinProtectsFromGC (2.92s)21822026/09/21 12:56:18 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-config21832026/09/21 12:56:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.048394ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21842026/09/21 12:56:18 WARN Rate limiter enabled after throttle name=s3-test rate=521852026/09/21 12:56:18 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2186=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2187 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102188 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002189--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.92s)21902026/09/21 12:56:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=387.848807ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21912026/09/21 12:56:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=782.411729ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21922026/09/21 12:56:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.598826619s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21932026/09/21 12:56:21 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"21942026/09/21 12:56:21 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_closures21952026/09/21 12:56:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.485641ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21962026/09/21 12:56:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.767881ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21972026/09/21 12:56:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=735.83728ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21982026/09/21 12:56:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.687342606s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2199--- PASS: TestClientErrorHandling (0.00s)2200 --- PASS: TestClientErrorHandling/InvalidStorePath (0.36s)2201 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.40s)2202 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.47s)2203PASS22042026-09-21 12:56:24.696 UTC [130] LOG: received smart shutdown request22052026-09-21 12:56:24.699 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 122062026-09-21 12:56:24.705 UTC [135] LOG: shutting down22072026-09-21 12:56:24.706 UTC [135] LOG: checkpoint starting: shutdown immediate22082026-09-21 12:56:25.919 UTC [135] LOG: checkpoint complete: wrote 11190 buffers (68.3%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 15 recycled; write=0.356 s, sync=0.818 s, total=1.214 s; sync files=18404, longest=0.004 s, average=0.001 s; distance=251189 kB, estimate=251189 kB; lsn=0/10CB33B8, redo lsn=0/10CB33B822092026-09-21 12:56:25.991 UTC [130] LOG: database system is shut down2210Running OIDC tests...2211=== RUN TestGlobMatch2212=== PAUSE TestGlobMatch2213=== RUN TestAudienceForIssuer2214=== PAUSE TestAudienceForIssuer2215=== RUN TestValidateToken_ValidToken2216=== PAUSE TestValidateToken_ValidToken2217=== RUN TestValidateToken_WrongAudience2218=== PAUSE TestValidateToken_WrongAudience2219=== RUN TestValidateToken_Expired2220=== PAUSE TestValidateToken_Expired2221=== RUN TestValidateToken_BoundClaimsMismatch2222=== PAUSE TestValidateToken_BoundClaimsMismatch2223=== RUN TestValidateToken_BoundSubjectMismatch2224=== PAUSE TestValidateToken_BoundSubjectMismatch2225=== RUN TestValidateToken_MultipleProviders2226=== PAUSE TestValidateToken_MultipleProviders2227=== RUN TestValidateToken_NoMatchingProvider2228=== PAUSE TestValidateToken_NoMatchingProvider2229=== RUN TestValidateToken_KubernetesServiceAccount2230=== PAUSE TestValidateToken_KubernetesServiceAccount2231=== RUN TestNewValidator_KubernetesRequiresCA2232=== PAUSE TestNewValidator_KubernetesRequiresCA2233=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2234=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2235=== RUN TestScopes_LegacyProviderDefaultsToWrite2236=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2237=== RUN TestScopes_Rules2238=== PAUSE TestScopes_Rules2239=== RUN TestScopes_ConfigValidation2240=== PAUSE TestScopes_ConfigValidation2241=== CONT TestGlobMatch2242=== CONT TestValidateToken_NoMatchingProvider2243=== CONT TestValidateToken_ValidToken2244=== RUN TestGlobMatch/foo_foo2245=== PAUSE TestGlobMatch/foo_foo2246=== CONT TestAudienceForIssuer2247=== CONT TestScopes_LegacyProviderDefaultsToWrite2248=== CONT TestScopes_ConfigValidation2249=== CONT TestScopes_Rules2250=== CONT TestValidateToken_WrongAudience2251=== CONT TestNewValidator_KubernetesRequiresCA2252=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2253=== CONT TestValidateToken_KubernetesServiceAccount2254=== CONT TestValidateToken_BoundSubjectMismatch2255=== CONT TestValidateToken_MultipleProviders2256=== CONT TestValidateToken_BoundClaimsMismatch2257=== CONT TestValidateToken_Expired2258=== RUN TestGlobMatch/foo_bar2259=== PAUSE TestGlobMatch/foo_bar2260--- PASS: TestAudienceForIssuer (0.00s)2261--- PASS: TestScopes_ConfigValidation (0.00s)2262=== RUN TestGlobMatch/*_2263=== PAUSE TestGlobMatch/*_22642026/09/21 12:56:27 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232265=== RUN TestGlobMatch/*_anything22662026/09/21 12:56:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40477/oidc22672026/09/21 12:56:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43959/oidc2268=== PAUSE TestGlobMatch/*_anything22692026/09/21 12:56:27 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43961/oidc2270=== RUN TestGlobMatch/foo*_foo2271=== PAUSE TestGlobMatch/foo*_foo2272=== RUN TestGlobMatch/foo*_foobar22732026/09/21 12:56:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45111/oidc2274=== PAUSE TestGlobMatch/foo*_foobar2275=== RUN TestGlobMatch/foo*_bar2276=== PAUSE TestGlobMatch/foo*_bar2277=== RUN TestGlobMatch/*bar_bar22782026/09/21 12:56:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32901/oidc2279=== PAUSE TestGlobMatch/*bar_bar2280=== RUN TestGlobMatch/*bar_foobar2281=== PAUSE TestGlobMatch/*bar_foobar2282=== RUN TestGlobMatch/*bar_foo2283=== PAUSE TestGlobMatch/*bar_foo2284=== RUN TestGlobMatch/foo*bar_foobar2285=== PAUSE TestGlobMatch/foo*bar_foobar2286=== RUN TestGlobMatch/foo*bar_foo123bar2287=== PAUSE TestGlobMatch/foo*bar_foo123bar2288=== RUN TestGlobMatch/foo*bar_foobarbaz2289=== PAUSE TestGlobMatch/foo*bar_foobarbaz2290=== RUN TestGlobMatch/*/*_foo/bar22912026/09/21 12:56:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43185/oidc2292=== PAUSE TestGlobMatch/*/*_foo/bar2293=== RUN TestGlobMatch/*/*_foo22942026/09/21 12:56:27 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41227/oidc2295=== PAUSE TestGlobMatch/*/*_foo2296=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2297=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2298=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02299=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02300=== RUN TestGlobMatch/refs/*/main_refs/heads/main2301=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2302=== RUN TestGlobMatch/fo?_foo2303=== PAUSE TestGlobMatch/fo?_foo2304=== RUN TestGlobMatch/fo?_fo2305=== PAUSE TestGlobMatch/fo?_fo23062026/09/21 12:56:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46879/oidc2307=== RUN TestGlobMatch/fo?_fooo2308=== PAUSE TestGlobMatch/fo?_fooo2309=== RUN TestGlobMatch/?oo_foo2310=== PAUSE TestGlobMatch/?oo_foo2311=== RUN TestGlobMatch/?oo_boo2312=== PAUSE TestGlobMatch/?oo_boo2313=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main23142026/09/21 12:56:27 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33785/oidc23152026/09/21 12:56:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38849/oidc2316=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2317=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2318=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2319=== CONT TestGlobMatch/foo_foo2320=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2321=== CONT TestGlobMatch/fo?_foo2322=== CONT TestGlobMatch/foo*_foobar2323=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2324=== CONT TestGlobMatch/*bar_bar2325=== CONT TestGlobMatch/?oo_boo2326=== CONT TestGlobMatch/foo_bar2327=== CONT TestGlobMatch/*_2328=== CONT TestGlobMatch/?oo_foo2329=== CONT TestGlobMatch/fo?_fooo2330=== CONT TestGlobMatch/fo?_fo2331=== CONT TestGlobMatch/*bar_foo2332=== CONT TestGlobMatch/foo*bar_foo123bar2333=== CONT TestGlobMatch/foo*bar_foobar2334=== CONT TestGlobMatch/*bar_foobar2335=== CONT TestGlobMatch/foo*bar_foobarbaz2336=== CONT TestGlobMatch/foo*_bar2337=== CONT TestGlobMatch/*_anything2338=== CONT TestGlobMatch/foo*_foo2339=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2340=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02341=== CONT TestGlobMatch/refs/*/main_refs/heads/main2342--- PASS: TestValidateToken_ValidToken (0.02s)2343--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2344=== CONT TestGlobMatch/*/*_foo/bar2345=== CONT TestGlobMatch/*/*_foo2346--- PASS: TestValidateToken_MultipleProviders (0.01s)2347--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)23482026/09/21 12:56:27 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:450832349--- PASS: TestValidateToken_WrongAudience (0.01s)2350--- PASS: TestGlobMatch (0.01s)2351 --- PASS: TestGlobMatch/foo_foo (0.00s)2352 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2353 --- PASS: TestGlobMatch/fo?_foo (0.00s)2354 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2355 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2356 --- PASS: TestGlobMatch/*bar_bar (0.00s)2357 --- PASS: TestGlobMatch/?oo_boo (0.00s)2358 --- PASS: TestGlobMatch/foo_bar (0.00s)2359 --- PASS: TestGlobMatch/*_ (0.00s)2360 --- PASS: TestGlobMatch/?oo_foo (0.00s)2361 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2362 --- PASS: TestGlobMatch/fo?_fo (0.00s)2363 --- PASS: TestGlobMatch/*bar_foo (0.00s)2364 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2365 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2366 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2367 --- PASS: TestGlobMatch/foo*_bar (0.00s)2368 --- PASS: TestGlobMatch/*_anything (0.00s)2369 --- PASS: TestGlobMatch/foo*_foo (0.00s)2370 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2371 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2372 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2373 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2374 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2375 --- PASS: TestGlobMatch/*/*_foo (0.00s)2376--- PASS: TestValidateToken_Expired (0.01s)2377--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2378--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2379--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2380--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2381--- PASS: TestScopes_Rules (0.02s)23822026/09/21 12:56:27 http: TLS handshake error from 127.0.0.1:52232: remote error: tls: bad certificate2383--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2384PASS2385Running hook tests...2386=== RUN TestSendPathsEmpty2387=== PAUSE TestSendPathsEmpty2388=== RUN TestQueueEnqueueAndFetch2389=== PAUSE TestQueueEnqueueAndFetch2390=== RUN TestQueueDeduplication2391=== PAUSE TestQueueDeduplication2392=== RUN TestQueueRemove2393=== PAUSE TestQueueRemove2394=== RUN TestQueueFetchBatchLimit2395=== PAUSE TestQueueFetchBatchLimit2396=== RUN TestQueueRetryMovesToBack2397=== PAUSE TestQueueRetryMovesToBack2398=== RUN TestQueueFetchRemoveLifecycle2399=== PAUSE TestQueueFetchRemoveLifecycle2400=== RUN TestQueueConcurrentWriters2401=== PAUSE TestQueueConcurrentWriters2402=== RUN TestQueueRemoveLargeClosure2403=== PAUSE TestQueueRemoveLargeClosure2404=== RUN TestServerClientIntegration2405=== PAUSE TestServerClientIntegration2406=== RUN TestServerQueueError2407=== PAUSE TestServerQueueError2408=== RUN TestGetListenerSocketActivation2409 server_test.go:210: === RUN TestGetListenerSocketActivation2410 --- PASS: TestGetListenerSocketActivation (0.00s)2411 PASS2412 2413--- PASS: TestGetListenerSocketActivation (0.01s)2414=== RUN TestDrainIsolatesPoisonPath2415=== PAUSE TestDrainIsolatesPoisonPath2416=== RUN TestRunNotBlockedByPoisonHead2417=== PAUSE TestRunNotBlockedByPoisonHead2418=== RUN TestDrainGivesUpWhenServerDown2419=== PAUSE TestDrainGivesUpWhenServerDown2420=== RUN TestFailedPathPrunedByLaterClosure2421=== PAUSE TestFailedPathPrunedByLaterClosure2422=== RUN TestWorkerUploadsAndRemoves2423=== PAUSE TestWorkerUploadsAndRemoves2424=== RUN TestWorkerSkipsGCdPaths2425=== PAUSE TestWorkerSkipsGCdPaths2426=== RUN TestWorkerPrunesClosureDeps2427=== PAUSE TestWorkerPrunesClosureDeps2428=== RUN TestDrainTimeout2429=== PAUSE TestDrainTimeout2430=== CONT TestSendPathsEmpty2431=== CONT TestQueueRemoveLargeClosure2432=== CONT TestQueueRemove2433=== CONT TestQueueDeduplication2434--- PASS: TestSendPathsEmpty (0.00s)2435=== CONT TestDrainTimeout2436=== CONT TestWorkerPrunesClosureDeps2437=== CONT TestWorkerSkipsGCdPaths2438=== CONT TestWorkerUploadsAndRemoves2439=== CONT TestFailedPathPrunedByLaterClosure2440=== CONT TestDrainGivesUpWhenServerDown2441=== CONT TestRunNotBlockedByPoisonHead2442=== CONT TestDrainIsolatesPoisonPath2443=== CONT TestQueueRetryMovesToBack2444=== CONT TestServerClientIntegration2445=== CONT TestServerQueueError2446=== CONT TestQueueEnqueueAndFetch2447=== CONT TestQueueConcurrentWriters2448=== CONT TestQueueFetchBatchLimit2449=== CONT TestQueueFetchRemoveLifecycle24502026/09/21 12:56:27 ERROR Failed to queue paths error="permission denied" count=12451--- PASS: TestServerQueueError (0.00s)2452--- PASS: TestServerClientIntegration (0.00s)24532026/09/21 12:56:27 INFO Uploading batch count=224542026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=224552026/09/21 12:56:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown912093530/002/a24562026/09/21 12:56:27 INFO Upload queue status pending=224572026/09/21 12:56:27 INFO Upload queue status pending=224582026/09/21 12:56:27 INFO Uploading batch count=12459--- PASS: TestQueueDeduplication (0.02s)24602026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=124612026/09/21 12:56:27 INFO Upload queue status pending=324622026/09/21 12:56:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown912093530/002/b24632026/09/21 12:56:27 INFO Uploading batch count=12464--- PASS: TestQueueFetchBatchLimit (0.01s)24652026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=124662026/09/21 12:56:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1486891685/002/nonexistent24672026/09/21 12:56:27 INFO Upload queue status pending=224682026/09/21 12:56:27 INFO Uploading batch count=224692026/09/21 12:56:27 INFO Uploading batch count=224702026/09/21 12:56:27 INFO Uploading batch count=424712026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=424722026/09/21 12:56:27 INFO Uploading batch count=224732026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=224742026/09/21 12:56:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown912093530/002/c24752026/09/21 12:56:27 INFO Uploading batch count=124762026/09/21 12:56:27 INFO Uploading batch count=124772026/09/21 12:56:27 INFO Uploading batch count=12478--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2479--- PASS: TestQueueEnqueueAndFetch (0.02s)2480--- PASS: TestQueueRetryMovesToBack (0.02s)24812026/09/21 12:56:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown912093530/002/d24822026/09/21 12:56:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1785262621/002/bbb24832026/09/21 12:56:27 INFO Uploading batch count=12484--- PASS: TestQueueRemove (0.02s)24852026/09/21 12:56:27 INFO Uploading batch count=224862026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=224872026/09/21 12:56:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown912093530/002/e24882026/09/21 12:56:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown912093530/002/f24892026/09/21 12:56:27 INFO Uploading batch count=124902026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=124912026/09/21 12:56:27 ERROR Drain finished with paths left in queue remaining=1024922026/09/21 12:56:27 INFO Uploading batch count=124932026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=12494--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24952026/09/21 12:56:27 INFO Uploading batch count=124962026/09/21 12:56:27 ERROR Upload failed error="upload failed" count=124972026/09/21 12:56:27 ERROR Drain finished with paths left in queue remaining=12498--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2499--- PASS: TestDrainIsolatesPoisonPath (0.02s)2500--- PASS: TestWorkerSkipsGCdPaths (0.03s)2501--- PASS: TestWorkerPrunesClosureDeps (0.04s)2502--- PASS: TestWorkerUploadsAndRemoves (0.04s)25032026/09/21 12:56:27 ERROR Upload failed error="context deadline exceeded" count=225042026/09/21 12:56:27 ERROR Drain finished with paths left in queue remaining=42505--- PASS: TestQueueRemoveLargeClosure (0.26s)2506--- PASS: TestDrainTimeout (0.26s)2507--- PASS: TestQueueConcurrentWriters (0.88s)25082026/09/21 12:56:28 INFO Uploading batch count=125092026/09/21 12:56:28 INFO Uploading batch count=125102026/09/21 12:56:28 INFO Uploading batch count=125112026/09/21 12:56:28 ERROR Upload failed error="upload failed" count=125122026/09/21 12:56:28 INFO Uploading batch count=125132026/09/21 12:56:28 ERROR Upload failed error="upload failed" count=125142026/09/21 12:56:28 INFO Uploading batch count=125152026/09/21 12:56:28 ERROR Upload failed error="upload failed" count=125162026/09/21 12:56:28 INFO Uploading batch count=125172026/09/21 12:56:28 ERROR Upload failed error="upload failed" count=125182026/09/21 12:56:28 ERROR Drain finished with paths left in queue remaining=12519--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2520PASS