niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.x86_64-linux.go-unit-tests` · build #226 · 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--- PASS: TestShellSplit (0.00s)93=== RUN TestConvertHashToNix32/SRI_format_to_Nix3294=== CONT TestStaticToken95--- PASS: TestStaticToken (0.00s)96=== CONT TestDoWithRetry_BodyReplayedViaGetBody97=== CONT TestResolveStorePath98=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestDumpPathSingleFile102=== CONT TestRateLimiterFeedback103=== CONT TestPathInfoCACompatibility104=== RUN TestRateLimiterFeedback/429_enables_limiter105=== RUN TestPathInfoCACompatibility/null_ca_field106=== PAUSE TestPathInfoCACompatibility/null_ca_field107=== RUN TestPathInfoCACompatibility/old_string_format_-_text108=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text109=== CONT TestParsePathInfoJSONMultiplePaths110=== CONT TestPathInfoHashCompatibility111=== CONT TestScriptTokenScriptFails112=== CONT TestGetStorePathHash1132026/09/20 10:36:44 WARN Rate limiter enabled after throttle name=server-test rate=5114=== CONT TestScriptTokenBadJSON115=== CONT TestScriptTokenNoExpiryRerunsEveryCall116=== CONT TestFileTokenEmpty117=== CONT TestScriptTokenEmptyToken118=== CONT TestFileTokenMissing119=== CONT TestScriptTokenCachesUntilRefresh120=== CONT TestDumpPathMatchesNix121=== CONT TestFilterOversizedClosures122=== CONT TestFileTokenReadsAndCaches123=== CONT TestDumpPathWriterError124=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32125=== CONT TestUploadMultipart_SupersededByPeer126=== CONT TestParsePathInfoJSON127=== PAUSE TestRateLimiterFeedback/429_enables_limiter128=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive129=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths130=== RUN TestRateLimiterFeedback/503_enables_limiter131=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)132=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)133=== RUN TestFilterOversizedClosures/no_limit_keeps_everything134=== PAUSE TestRateLimiterFeedback/503_enables_limiter135=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter136=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter137=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter138=== CONT TestPartSizeForNAR139=== RUN TestPartSizeForNAR/zero_stays_at_minimum140=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum141--- PASS: TestResolveStorePath (0.00s)142=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon143=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon144=== RUN TestGetStorePathHash/valid_store_path145=== PAUSE TestGetStorePathHash/valid_store_path146=== RUN TestGetStorePathHash/basename_without_hyphen_should_error147=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter148=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI149=== RUN TestPartSizeForNAR/small_stays_at_minimum150=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error151=== RUN TestConvertHashToNix32/already_Nix32_format152=== CONT TestStreamPushBatchesUnderLoad153=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error154--- PASS: TestFileTokenEmpty (0.00s)155=== CONT TestStreamPushIsolatesFailures156--- PASS: TestFileTokenMissing (0.00s)157=== CONT TestSetClientTLS158--- PASS: TestFileTokenReadsAndCaches (0.00s)159=== CONT TestStreamPushGivesUpOnDeadServer160=== RUN TestUploadMultipart_SupersededByPeer/exists161=== RUN TestParsePathInfoJSON/Nix_format162=== PAUSE TestParsePathInfoJSON/Nix_format163--- PASS: TestScriptTokenScriptFails (0.00s)164=== RUN TestParsePathInfoJSON/Lix_format165=== PAUSE TestParsePathInfoJSON/Lix_format166=== RUN TestParsePathInfoJSON/empty_input167=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive168=== PAUSE TestConvertHashToNix32/already_Nix32_format1692026/09/20 10:36:44 WARN Rate limiter enabled after throttle name=server-test rate=5170=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1712026/09/20 10:36:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34871172=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths173=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths174=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything175=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error1762026/09/20 10:36:44 ERROR Upload failed error="bad path" count=31772026/09/20 10:36:44 ERROR Upload failed error="connection refused" count=20178=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error1792026/09/20 10:36:44 ERROR Server seems unavailable, giving up on batch untried=17180=== PAUSE TestUploadMultipart_SupersededByPeer/exists181=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI182=== PAUSE TestParsePathInfoJSON/empty_input183=== RUN TestParsePathInfoJSON/whitespace_only184=== CONT TestSetClientTLSErrors185=== PAUSE TestPartSizeForNAR/small_stays_at_minimum186=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum187=== RUN TestPathInfoCACompatibility/new_structured_format_-_text188=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text189=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method1902026/09/20 10:36:44 WARN Rate limiter backed off name=server-test rate=5191=== CONT TestCaseHackSuffix1922026/09/20 10:36:44 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34871193=== CONT TestSetClientTLSDoesNotMutateDefaultTransport194=== CONT TestStreamPushReportsEveryPath195=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped196=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped197=== CONT TestRegisterUploadedObjectReusesConnections198=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error199=== RUN TestUploadMultipart_SupersededByPeer/missing200--- PASS: TestDoServerRequestAttachesToken (0.01s)201=== CONT TestEncodeNixBase32WithRealHash202=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512203=== PAUSE TestParsePathInfoJSON/whitespace_only204=== PAUSE TestUploadMultipart_SupersededByPeer/missing205=== RUN TestParsePathInfoJSON/invalid_JSON206=== CONT TestStreamPushRequestLine207=== RUN TestConvertHashToNix32/invalid_format208=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method209=== RUN TestFilterOversizedClosures/all_closures_skipped210=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter211=== PAUSE TestFilterOversizedClosures/all_closures_skipped212=== CONT TestShellSplitErrors213=== PAUSE TestParsePathInfoJSON/invalid_JSON214=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths215=== RUN TestSetClientTLSErrors/missing_cert_file216--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)217--- PASS: TestStreamPushIsolatesFailures (0.00s)218--- PASS: TestScriptTokenEmptyToken (0.01s)219--- PASS: TestScriptTokenBadJSON (0.00s)220--- PASS: TestStreamPushReportsEveryPath (0.00s)221--- PASS: TestEncodeNixBase32WithRealHash (0.00s)222--- PASS: TestShellSplitErrors (0.00s)2232026/09/20 10:36:44 ERROR Upload failed error=boom count=1224=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error225=== PAUSE TestSetClientTLSErrors/missing_cert_file226=== CONT TestGetStorePathHash/basename_without_hyphen_should_error227=== RUN TestSetClientTLSErrors/missing_key_file228=== CONT TestUploadMultipart_SupersededByPeer/exists229=== PAUSE TestSetClientTLSErrors/missing_key_file230=== CONT TestRateLimiterFeedback/429_enables_limiter231=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter232=== CONT TestRateLimiterFeedback/503_enables_limiter2332026/09/20 10:36:44 WARN Rate limiter enabled after throttle name=server-test rate=5234=== CONT TestEncodeNixBase322352026/09/20 10:36:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42943236=== RUN TestEncodeNixBase32/test_string_hash237=== PAUSE TestEncodeNixBase32/test_string_hash238=== CONT TestGetStorePathHash/valid_store_path239=== RUN TestSetClientTLS/rejects_connection_without_client_cert2402026/09/20 10:36:44 WARN Rate limiter backed off name=server-test rate=5241=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error242=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths243=== PAUSE TestConvertHashToNix32/invalid_format244=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum245--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)246=== CONT TestUploadMultipart_SupersededByPeer/missing247=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5122482026/09/20 10:36:44 WARN Rate limiter enabled after throttle name=server-test rate=5249=== CONT TestPathInfoCACompatibility/null_ca_field2502026/09/20 10:36:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:38577251=== RUN TestSetClientTLSErrors/missing_ca_file252=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method253=== RUN TestEncodeNixBase32/empty_input254=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive255=== CONT TestFilterOversizedClosures/no_limit_keeps_everything2562026/09/20 10:36:44 WARN Rate limiter backed off name=server-test rate=5257=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert258=== CONT TestFilterOversizedClosures/all_closures_skipped259=== CONT TestPathInfoCACompatibility/old_string_format_-_text2602026/09/20 10:36:44 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50261=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped262=== CONT TestConvertHashToNix32/already_Nix32_format2632026/09/20 10:36:44 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=2000264=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)265=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts266=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts267--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)268=== CONT TestParsePathInfoJSON/Nix_format269=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512270=== RUN TestPartSizeForNAR/1_TiB271=== CONT TestPathInfoCACompatibility/new_structured_format_-_text272=== CONT TestParsePathInfoJSON/whitespace_only273=== PAUSE TestSetClientTLSErrors/missing_ca_file274=== PAUSE TestEncodeNixBase32/empty_input275=== CONT TestParsePathInfoJSON/invalid_JSON276=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA277=== CONT TestParsePathInfoJSON/empty_input278=== CONT TestParsePathInfoJSON/Lix_format279=== CONT TestConvertHashToNix32/SRI_format_to_Nix32280=== CONT TestConvertHashToNix32/invalid_format281=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI282=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon283--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)284=== PAUSE TestPartSizeForNAR/1_TiB285=== RUN TestSetClientTLSErrors/invalid_ca_file286=== PAUSE TestSetClientTLSErrors/invalid_ca_file287=== CONT TestEncodeNixBase32/test_string_hash288=== CONT TestEncodeNixBase32/empty_input289=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA290--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)291=== RUN TestPartSizeForNAR/5_TiB_S3_max_object292=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object293--- PASS: TestGetStorePathHash (0.01s)294 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)295 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.01s)296 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)297 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)298=== CONT TestSetClientTLSErrors/missing_cert_file299=== CONT TestSetClientTLSErrors/missing_ca_file300=== CONT TestSetClientTLSErrors/missing_key_file301=== CONT TestSetClientTLSErrors/invalid_ca_file302=== RUN TestSetClientTLS/preserves_debug_logging_transport303=== RUN TestPartSizeForNAR/capped_at_5_GiB304=== PAUSE TestPartSizeForNAR/capped_at_5_GiB305=== CONT TestPartSizeForNAR/zero_stays_at_minimum306=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts307=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum308--- PASS: TestRateLimiterFeedback (0.00s)309 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)310 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)311 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)312 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)313=== CONT TestPartSizeForNAR/1_TiB314=== PAUSE TestSetClientTLS/preserves_debug_logging_transport315=== CONT TestSetClientTLS/rejects_connection_without_client_cert316=== CONT TestSetClientTLS/preserves_debug_logging_transport317=== CONT TestPartSizeForNAR/5_TiB_S3_max_object318=== CONT TestPartSizeForNAR/small_stays_at_minimum319--- PASS: TestFilterOversizedClosures (0.01s)320 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)321 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)322 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)323--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)324 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)325 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)326=== CONT TestPartSizeForNAR/capped_at_5_GiB327=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA328--- PASS: TestPathInfoCACompatibility (0.01s)329 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)330 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)331 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)332 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)333 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)334--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)335 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)336 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)337--- PASS: TestConvertHashToNix32 (0.03s)338 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)339 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)340 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)341--- PASS: TestParsePathInfoJSON (0.01s)342 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)343 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)344 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)345 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)346 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)347--- PASS: TestEncodeNixBase32 (0.00s)348 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)349 --- PASS: TestEncodeNixBase32/empty_input (0.00s)350--- PASS: TestPathInfoHashCompatibility (0.02s)351 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)352 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)353 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)354 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)355--- PASS: TestPartSizeForNAR (0.03s)356 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)357 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)358 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)359 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)360 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)361 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)363--- PASS: TestSetClientTLSErrors (0.02s)364 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)365 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)366 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)367 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)368--- PASS: TestDumpPathSingleFile (0.03s)3692026/09/20 10:36:44 http: TLS handshake error from 127.0.0.1:49564: remote error: tls: bad certificate370--- PASS: TestSetClientTLS (0.03s)371 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)372 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)373 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)374--- PASS: TestStreamPushRequestLine (0.03s)375--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)376--- PASS: TestCaseHackSuffix (0.05s)377--- PASS: TestDumpPathWriterError (0.06s)378--- PASS: TestDumpPathMatchesNix (0.10s)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/postgres2672943789/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/postgres2672943789/data -l logfile start409410/build/postgres2672943789:5432 - no response4112026-09-20 10:36:45.998 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4122026-09-20 10:36:45.999 UTC [129] LOG: listening on Unix socket "/build/postgres2672943789/.s.PGSQL.5432"4132026-09-20 10:36:46.003 UTC [136] LOG: database system was shut down at 2026-09-20 10:36:45 UTC4142026-09-20 10:36:46.007 UTC [129] LOG: database system is ready to accept connections415/build/postgres2672943789: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-20 10:36:46.386 UTC [565] ERROR: relation "goose_db_version" does not exist at character 364562026-09-20 10:36:46.386 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4572026/09/20 10:36:46 OK 20241026095416_initial_model.sql (7.06ms)4582026/09/20 10:36:46 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)4592026/09/20 10:36:46 OK 20251218171726_add_pins.sql (1.96ms)4602026/09/20 10:36:46 OK 20260628120000_add_object_size_and_stats.sql (2.05ms)4612026/09/20 10:36:46 OK 20260905000000_add_claims.sql (1.94ms)4622026/09/20 10:36:46 OK 20260920000000_drop_claims.sql (1.26ms)4632026/09/20 10:36:46 goose: successfully migrated database to version: 202609200000004642026/09/20 10:36:46 OK 1_commit_pending_closure.sql (1.61ms)4652026/09/20 10:36:46 OK 2_object_stats_trigger.sql (586.21µs)4662026/09/20 10:36:46 goose: up to current file version: 2467--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.14s)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/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5682026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5692026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5702026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/20 10:36:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/20 10:36:46 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 TestCreatePendingClosure_SmallNARUsesSimplePUT600=== CONT TestReadProxy404601=== CONT TestGCTaskStore_GetReturnsLatest602=== CONT TestClientWithDependencies603--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)604=== CONT TestService_ReadScope_PublicByDefault605=== CONT TestGCTaskStore_ConflictDifferentParams606--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)607=== CONT TestGCTaskStore_DeduplicateSameParams608=== CONT TestGCTaskStore_StartNew609=== CONT TestGCMetrics610=== CONT TestGCBugBareHashReferences611=== CONT TestLeadEndsOnShutdown612=== CONT TestLeadElectsOneAndHandsOver613=== CONT TestResolveDBConnectionString614=== CONT TestPinProtectsFromGC615=== CONT TestClientSharedPathCommittedMidPush616=== CONT TestClientErrorHandling617=== CONT TestClientMultipleUploads618=== CONT TestCacheConfigHandler619=== CONT TestClientIntegration620=== CONT TestClientCADerivations621=== CONT TestService_AuthMiddleware_OIDC622=== CONT TestCacheStatsHandler623=== CONT TestReadProxyInvalidPath624=== CONT TestGCTaskStore_GetEmpty625=== CONT TestService_RequireScope_OIDC626=== RUN TestCacheConfigHandler/full_config,_no_issuer627=== PAUSE TestCacheConfigHandler/full_config,_no_issuer628=== RUN TestCacheConfigHandler/no_cache_url_configured629=== PAUSE TestCacheConfigHandler/no_cache_url_configured630=== RUN TestCacheConfigHandler/no_signing_keys631=== PAUSE TestCacheConfigHandler/no_signing_keys632=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator633=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator634=== CONT TestService_NativeMTLS635=== CONT TestService_AuthMiddleware_MTLSProxyHeader636--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)637--- PASS: TestGCTaskStore_StartNew (0.00s)638--- PASS: TestGCTaskStore_GetEmpty (0.00s)639=== CONT TestService_AuthMiddleware_MTLSBoundSubjects640=== CONT TestService_ReadAuthMiddleware641=== RUN TestResolveDBConnectionString/flag_wins642=== RUN TestClientErrorHandling/InvalidStorePath643=== PAUSE TestResolveDBConnectionString/flag_wins644=== PAUSE TestClientErrorHandling/InvalidStorePath645=== RUN TestResolveDBConnectionString/file_when_flag_empty646=== PAUSE TestResolveDBConnectionString/file_when_flag_empty647=== RUN TestClientErrorHandling/InvalidAuthToken648=== RUN TestResolveDBConnectionString/missing_file_is_an_error649=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error650=== RUN TestResolveDBConnectionString/PGHOST_allows_empty6512026/09/20 10:36:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36471/oidc652=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty653=== RUN TestResolveDBConnectionString/nothing_configured654=== PAUSE TestResolveDBConnectionString/nothing_configured6552026/09/20 10:36:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32771/oidc656=== PAUSE TestClientErrorHandling/InvalidAuthToken657=== CONT TestReadProxyNarStreaming658=== RUN TestClientErrorHandling/ServerNotAvailable659=== PAUSE TestClientErrorHandling/ServerNotAvailable660=== CONT TestService_Rustfstest6612026-09-20 10:36:46.798 UTC [641] ERROR: relation "goose_db_version" does not exist at character 366622026-09-20 10:36:46.798 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6632026-09-20 10:36:46.799 UTC [642] ERROR: relation "goose_db_version" does not exist at character 366642026-09-20 10:36:46.799 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-09-20 10:36:46.848 UTC [643] ERROR: relation "goose_db_version" does not exist at character 366662026-09-20 10:36:46.848 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026-09-20 10:36:46.865 UTC [644] ERROR: relation "goose_db_version" does not exist at character 366682026-09-20 10:36:46.865 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6692026-09-20 10:36:46.963 UTC [645] ERROR: relation "goose_db_version" does not exist at character 366702026-09-20 10:36:46.963 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6712026-09-20 10:36:46.967 UTC [646] ERROR: relation "goose_db_version" does not exist at character 366722026-09-20 10:36:46.967 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6732026-09-20 10:36:47.000 UTC [647] ERROR: relation "goose_db_version" does not exist at character 366742026-09-20 10:36:47.000 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6752026/09/20 10:36:47 OK 20241026095416_initial_model.sql (166.13ms)6762026/09/20 10:36:47 OK 20241026095416_initial_model.sql (167.43ms)6772026/09/20 10:36:47 OK 20241026095416_initial_model.sql (58.27ms)6782026/09/20 10:36:47 OK 20241026095416_initial_model.sql (70.19ms)6792026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (8.26ms)6802026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)6812026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)6822026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)6832026/09/20 10:36:47 OK 20241026095416_initial_model.sql (21.45ms)6842026/09/20 10:36:47 OK 20251218171726_add_pins.sql (15.78ms)6852026/09/20 10:36:47 OK 20251218171726_add_pins.sql (14.6ms)6862026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (7.18ms)6872026/09/20 10:36:47 OK 20251218171726_add_pins.sql (72.67ms)6882026/09/20 10:36:47 OK 20251218171726_add_pins.sql (76.39ms)6892026/09/20 10:36:47 OK 20251218171726_add_pins.sql (89.65ms)6902026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (80.56ms)6912026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (81.55ms)6922026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (10.39ms)6932026/09/20 10:36:47 OK 20260905000000_add_claims.sql (10.6ms)6942026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (13.07ms)6952026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (30.01ms)6962026/09/20 10:36:47 OK 20260905000000_add_claims.sql (11.02ms)6972026/09/20 10:36:47 OK 20241026095416_initial_model.sql (103.36ms)6982026/09/20 10:36:47 OK 20241026095416_initial_model.sql (112.55ms)6992026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (6.67ms)7002026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000007012026/09/20 10:36:47 OK 20260905000000_add_claims.sql (10.37ms)7022026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (4.93ms)7032026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (6.55ms)7042026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000007052026/09/20 10:36:47 OK 20260905000000_add_claims.sql (9.43ms)7062026/09/20 10:36:47 OK 20260905000000_add_claims.sql (9.34ms)7072026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (6.24ms)7082026/09/20 10:36:47 OK 1_commit_pending_closure.sql (5.82ms)7092026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (6.57ms)7102026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000007112026/09/20 10:36:47 OK 1_commit_pending_closure.sql (5.85ms)7122026/09/20 10:36:47 OK 20251218171726_add_pins.sql (7.75ms)7132026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (6ms)7142026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000007152026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (5.37ms)7162026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000007172026/09/20 10:36:47 OK 2_object_stats_trigger.sql (4.48ms)7182026/09/20 10:36:47 goose: up to current file version: 27192026/09/20 10:36:47 OK 1_commit_pending_closure.sql (5.84ms)7202026-09-20 10:36:47.149 UTC [652] ERROR: relation "goose_db_version" does not exist at character 367212026-09-20 10:36:47.149 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-09-20 10:36:47.149 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367232026-09-20 10:36:47.149 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-09-20 10:36:47.150 UTC [653] ERROR: relation "goose_db_version" does not exist at character 367252026-09-20 10:36:47.150 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.93ms)7272026-09-20 10:36:47.150 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367282026-09-20 10:36:47.150 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7292026/09/20 10:36:47 goose: up to current file version: 27302026/09/20 10:36:47 OK 1_commit_pending_closure.sql (6.31ms)7312026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.68ms)7322026/09/20 10:36:47 goose: up to current file version: 27332026/09/20 10:36:47 OK 1_commit_pending_closure.sql (8.28ms)7342026/09/20 10:36:47 OK 20251218171726_add_pins.sql (8.24ms)7352026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.22ms)7362026/09/20 10:36:47 goose: up to current file version: 27372026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (10.24ms)7382026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.04ms)7392026/09/20 10:36:47 goose: up to current file version: 27402026-09-20 10:36:47.160 UTC [654] ERROR: relation "goose_db_version" does not exist at character 367412026-09-20 10:36:47.160 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026/09/20 10:36:47 OK 20260905000000_add_claims.sql (7.01ms)7432026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (8.7ms)7442026-09-20 10:36:47.168 UTC [655] ERROR: relation "goose_db_version" does not exist at character 367452026-09-20 10:36:47.168 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7462026/09/20 10:36:47 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"747--- PASS: TestService_AuthMiddleware (0.50s)748=== CONT TestReadProxyNarinfoAlreadyDecompressed7492026/09/20 10:36:47 OK 20260905000000_add_claims.sql (14.51ms)7502026/09/20 10:36:47 OK 20241026095416_initial_model.sql (16.19ms)7512026/09/20 10:36:47 OK 20241026095416_initial_model.sql (15.65ms)7522026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (16.29ms)7532026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000007542026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)7552026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)7562026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (4.08ms)7572026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000007582026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.33ms)7592026/09/20 10:36:47 OK 1_commit_pending_closure.sql (5.15ms)7602026-09-20 10:36:47.184 UTC [657] ERROR: relation "goose_db_version" does not exist at character 367612026-09-20 10:36:47.184 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7622026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.81ms)7632026/09/20 10:36:47 OK 20241026095416_initial_model.sql (11.36ms)7642026/09/20 10:36:47 OK 1_commit_pending_closure.sql (4.48ms)7652026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.83ms)7662026/09/20 10:36:47 goose: up to current file version: 27672026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)7682026-09-20 10:36:47.188 UTC [660] ERROR: relation "goose_db_version" does not exist at character 367692026-09-20 10:36:47.188 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.79ms)7712026/09/20 10:36:47 goose: up to current file version: 27722026/09/20 10:36:47 OK 20241026095416_initial_model.sql (11.17ms)7732026/09/20 10:36:47 OK 20241026095416_initial_model.sql (12.06ms)7742026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (6.21ms)7752026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)7762026-09-20 10:36:47.191 UTC [661] ERROR: relation "goose_db_version" does not exist at character 367772026-09-20 10:36:47.191 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7782026/09/20 10:36:47 OK 20241026095416_initial_model.sql (13.11ms)7792026-09-20 10:36:47.191 UTC [666] ERROR: relation "goose_db_version" does not exist at character 367802026-09-20 10:36:47.191 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026-09-20 10:36:47.191 UTC [664] ERROR: relation "goose_db_version" does not exist at character 367822026-09-20 10:36:47.191 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.01ms)7842026-09-20 10:36:47.192 UTC [662] ERROR: relation "goose_db_version" does not exist at character 367852026-09-20 10:36:47.192 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)7872026-09-20 10:36:47.193 UTC [663] ERROR: relation "goose_db_version" does not exist at character 367882026-09-20 10:36:47.193 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-09-20 10:36:47.193 UTC [665] ERROR: relation "goose_db_version" does not exist at character 367902026-09-20 10:36:47.193 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)7922026-09-20 10:36:47.193 UTC [667] ERROR: relation "goose_db_version" does not exist at character 367932026-09-20 10:36:47.193 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.44ms)7952026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)7962026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.24ms)7972026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.05ms)7982026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (5.35ms)7992026-09-20 10:36:47.197 UTC [668] ERROR: relation "goose_db_version" does not exist at character 368002026-09-20 10:36:47.197 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.96ms)8022026-09-20 10:36:47.198 UTC [669] ERROR: relation "goose_db_version" does not exist at character 368032026-09-20 10:36:47.198 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (4.34ms)8052026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008062026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.67ms)8072026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (4.2ms)8082026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008092026/09/20 10:36:47 INFO Received uploads request method=POST path=/api/pending_closures8102026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)8112026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.92ms)8122026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.11ms)8132026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.26ms)8142026/09/20 10:36:47 OK 20241026095416_initial_model.sql (10.61ms)8152026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)8162026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.81ms)8172026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008182026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.52ms)8192026/09/20 10:36:47 goose: up to current file version: 28202026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)8212026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (6.64ms)8222026/09/20 10:36:47 OK 20260905000000_add_claims.sql (5.49ms)8232026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.3ms)8242026/09/20 10:36:47 goose: up to current file version: 28252026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.15ms)8262026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.23ms)8272026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.22ms)8282026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008292026/09/20 10:36:47 OK 20241026095416_initial_model.sql (13.83ms)8302026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.1ms)8312026/09/20 10:36:47 OK 20241026095416_initial_model.sql (13.98ms)8322026/09/20 10:36:47 OK 20251218171726_add_pins.sql (6.99ms)8332026/09/20 10:36:47 OK 20241026095416_initial_model.sql (13.42ms)8342026/09/20 10:36:47 OK 20241026095416_initial_model.sql (14.12ms)8352026/09/20 10:36:47 OK 20241026095416_initial_model.sql (13.21ms)8362026/09/20 10:36:47 OK 20260905000000_add_claims.sql (6.96ms)8372026/09/20 10:36:47 OK 2_object_stats_trigger.sql (4.24ms)8382026/09/20 10:36:47 goose: up to current file version: 28392026/09/20 10:36:47 OK 20241026095416_initial_model.sql (14.48ms)8402026/09/20 10:36:47 OK 20241026095416_initial_model.sql (12.34ms)8412026/09/20 10:36:47 OK 20241026095416_initial_model.sql (12.39ms)8422026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)8432026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (6.43ms)8442026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008452026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.9ms)8462026/09/20 10:36:47 goose: up to current file version: 28472026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)8482026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)8492026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)8502026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)8512026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)8522026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)8532026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.96ms)8542026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008552026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)8562026/09/20 10:36:47 OK 20251218171726_add_pins.sql (3.65ms)8572026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.47ms)8582026/09/20 10:36:47 OK 20241026095416_initial_model.sql (10.74ms)8592026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)8602026/09/20 10:36:47 OK 20241026095416_initial_model.sql (11.24ms)8612026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.8ms)8622026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.28ms)863--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)864=== CONT TestReadProxyNarinfo8652026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.73ms)8662026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.12ms)8672026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.26ms)8682026/09/20 10:36:47 goose: up to current file version: 28692026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)8702026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)8712026/09/20 10:36:47 OK 20251218171726_add_pins.sql (5.16ms)8722026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.72ms)8732026/09/20 10:36:47 goose: up to current file version: 28742026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)8752026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)8762026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.73ms)8772026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.91ms)8782026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.58ms)8792026/09/20 10:36:47 OK 20251218171726_add_pins.sql (5.07ms)8802026/09/20 10:36:47 OK 20251218171726_add_pins.sql (3.54ms)8812026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.73ms)8822026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008832026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.06ms)8842026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.02ms)8852026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)8862026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.1ms)8872026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)8882026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)8892026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)8902026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)8912026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)8922026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.1ms)8932026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008942026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.29ms)8952026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.64ms)8962026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000008972026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.2ms)8982026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)8992026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.15ms)9002026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.01ms)9012026/09/20 10:36:47 goose: up to current file version: 29022026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)9032026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.52ms)9042026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.9ms)9052026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.1ms)9062026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.98ms)9072026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.96ms)9082026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.26ms)9092026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.46ms)9102026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009112026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.33ms)9122026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009132026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.35ms)9142026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.93ms)9152026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009162026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.35ms)9172026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009182026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.73ms)9192026/09/20 10:36:47 goose: up to current file version: 29202026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.89ms)9212026/09/20 10:36:47 goose: up to current file version: 29222026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.75ms)9232026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.6ms)9242026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.55ms)9252026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009262026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.84ms)9272026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.43ms)9282026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009292026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.36ms)9302026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009312026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.74ms)9322026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.77ms)9332026/09/20 10:36:47 goose: up to current file version: 29342026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.71ms)9352026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.95ms)9362026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.92ms)9372026/09/20 10:36:47 OK 2_object_stats_trigger.sql (3.15ms)9382026/09/20 10:36:47 goose: up to current file version: 29392026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.86ms)9402026/09/20 10:36:47 goose: up to current file version: 29412026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.31ms)9422026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (4.16ms)9432026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000009442026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.45ms)9452026/09/20 10:36:47 goose: up to current file version: 29462026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.54ms)9472026/09/20 10:36:47 goose: up to current file version: 29482026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.18ms)9492026/09/20 10:36:47 goose: up to current file version: 29502026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.33ms)9512026/09/20 10:36:47 goose: up to current file version: 29522026/09/20 10:36:47 OK 1_commit_pending_closure.sql (1.92ms)9532026/09/20 10:36:47 OK 2_object_stats_trigger.sql (933.51µs)9542026/09/20 10:36:47 goose: up to current file version: 2955--- PASS: TestReadProxy404 (0.58s)956=== CONT TestCompleteMultipartUnregistered9572026-09-20 10:36:47.291 UTC [692] ERROR: relation "goose_db_version" does not exist at character 369582026-09-20 10:36:47.291 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC959--- PASS: TestService_ReadScope_PublicByDefault (0.63s)960=== CONT TestIsValidCachePath961=== RUN TestIsValidCachePath/narinfo962=== PAUSE TestIsValidCachePath/narinfo963=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars964=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars965=== RUN TestIsValidCachePath/nar_zst966=== PAUSE TestIsValidCachePath/nar_zst967=== RUN TestIsValidCachePath/nar_xz968=== PAUSE TestIsValidCachePath/nar_xz969=== RUN TestIsValidCachePath/nar_bz2970=== PAUSE TestIsValidCachePath/nar_bz2971=== RUN TestIsValidCachePath/nar_uncompressed972=== PAUSE TestIsValidCachePath/nar_uncompressed973=== RUN TestIsValidCachePath/ls974=== PAUSE TestIsValidCachePath/ls975=== RUN TestIsValidCachePath/log976=== PAUSE TestIsValidCachePath/log977=== RUN TestIsValidCachePath/realisation978=== PAUSE TestIsValidCachePath/realisation979=== RUN TestIsValidCachePath/nix-cache-info980=== PAUSE TestIsValidCachePath/nix-cache-info981=== RUN TestIsValidCachePath/index.html982=== PAUSE TestIsValidCachePath/index.html983=== RUN TestIsValidCachePath/traversal_parent984=== PAUSE TestIsValidCachePath/traversal_parent985=== RUN TestIsValidCachePath/traversal_in_middle986=== PAUSE TestIsValidCachePath/traversal_in_middle987=== RUN TestIsValidCachePath/invalid_char_e988=== PAUSE TestIsValidCachePath/invalid_char_e989=== RUN TestIsValidCachePath/invalid_char_u990=== PAUSE TestIsValidCachePath/invalid_char_u991=== RUN TestIsValidCachePath/random_path992=== PAUSE TestIsValidCachePath/random_path993=== RUN TestIsValidCachePath/empty994=== PAUSE TestIsValidCachePath/empty995=== RUN TestIsValidCachePath/leading_slash996=== PAUSE TestIsValidCachePath/leading_slash997=== RUN TestIsValidCachePath/wrong_extension998=== PAUSE TestIsValidCachePath/wrong_extension999=== RUN TestIsValidCachePath/short_hash1000=== PAUSE TestIsValidCachePath/short_hash1001=== CONT TestService_verifyS3Integrity1002=== NAME TestClientWithDependencies1003 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2149776402/001/store/a44xvrpahc2p5n13k64bzkw06lzabvnc-test-script10042026/09/20 10:36:47 OK 20241026095416_initial_model.sql (8.89ms)10052026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)10062026-09-20 10:36:47.316 UTC [712] ERROR: relation "goose_db_version" does not exist at character 3610072026-09-20 10:36:47.316 UTC [712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10082026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.41ms)10092026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)10102026/09/20 10:36:47 OK 20260905000000_add_claims.sql (2.8ms)10112026/09/20 10:36:47 INFO lead: acquired remote=192.0.2.1:123410122026/09/20 10:36:47 INFO lead: released remote=192.0.2.1:12341013--- PASS: TestLeadEndsOnShutdown (0.65s)1014=== CONT TestParseSingleRange1015=== RUN TestParseSingleRange/none1016=== PAUSE TestParseSingleRange/none1017=== RUN TestParseSingleRange/unknown_unit1018=== PAUSE TestParseSingleRange/unknown_unit1019=== RUN TestParseSingleRange/multi-range_ignored1020=== PAUSE TestParseSingleRange/multi-range_ignored1021=== RUN TestParseSingleRange/malformed_no_dash1022=== PAUSE TestParseSingleRange/malformed_no_dash1023=== RUN TestParseSingleRange/malformed_both_empty1024=== PAUSE TestParseSingleRange/malformed_both_empty1025=== RUN TestParseSingleRange/malformed_end_before_start1026=== PAUSE TestParseSingleRange/malformed_end_before_start1027=== RUN TestParseSingleRange/closed1028=== PAUSE TestParseSingleRange/closed1029=== RUN TestParseSingleRange/open-ended1030=== PAUSE TestParseSingleRange/open-ended1031=== RUN TestParseSingleRange/end_clamped_to_size1032=== PAUSE TestParseSingleRange/end_clamped_to_size1033=== RUN TestParseSingleRange/suffix10342026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.41ms)1035=== PAUSE TestParseSingleRange/suffix10362026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000001037=== RUN TestParseSingleRange/suffix_exceeds_size1038=== PAUSE TestParseSingleRange/suffix_exceeds_size1039=== RUN TestParseSingleRange/single_byte1040=== PAUSE TestParseSingleRange/single_byte1041=== RUN TestParseSingleRange/start_past_EOF1042=== PAUSE TestParseSingleRange/start_past_EOF1043=== RUN TestParseSingleRange/start_far_past_EOF1044=== PAUSE TestParseSingleRange/start_far_past_EOF1045=== CONT TestService_createPendingClosureHandler10462026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.51ms)10472026/09/20 10:36:47 OK 20241026095416_initial_model.sql (7.73ms)10482026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.66ms)10492026/09/20 10:36:47 goose: up to current file version: 210502026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)10512026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.54ms)10522026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)10532026/09/20 10:36:47 OK 20260905000000_add_claims.sql (2.9ms)10542026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (1.98ms)10552026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000010562026-09-20 10:36:47.344 UTC [717] ERROR: relation "goose_db_version" does not exist at character 3610572026-09-20 10:36:47.344 UTC [717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10582026/09/20 10:36:47 OK 1_commit_pending_closure.sql (1.69ms)10592026/09/20 10:36:47 INFO lead: acquired remote=192.0.2.1:123410602026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.82ms)10612026/09/20 10:36:47 goose: up to current file version: 21062=== NAME TestClientWithDependencies1063 client_integration_test.go:615: Found 1 dependencies (including self)10642026/09/20 10:36:47 OK 20241026095416_initial_model.sql (9.14ms)10652026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)10662026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.29ms)10672026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3ms)10682026/09/20 10:36:47 OK 20260905000000_add_claims.sql (2.79ms)10692026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (1.67ms)10702026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000010712026/09/20 10:36:47 OK 1_commit_pending_closure.sql (1.61ms)10722026/09/20 10:36:47 OK 2_object_stats_trigger.sql (955.32µs)10732026/09/20 10:36:47 goose: up to current file version: 210742026-09-20 10:36:47.385 UTC [753] ERROR: relation "goose_db_version" does not exist at character 3610752026-09-20 10:36:47.385 UTC [753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10762026/09/20 10:36:47 OK 20241026095416_initial_model.sql (7.6ms)10772026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (844.78µs)10782026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.03ms)1079--- PASS: TestCacheStatsHandler (0.73s)1080=== CONT TestResurrectedObjectNotDeleted10812026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (2.33ms)10822026/09/20 10:36:47 OK 20260905000000_add_claims.sql (2.18ms)10832026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (1.46ms)10842026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000010852026-09-20 10:36:47.408 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3610862026-09-20 10:36:47.408 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10872026/09/20 10:36:47 OK 1_commit_pending_closure.sql (1.35ms)10882026/09/20 10:36:47 OK 2_object_stats_trigger.sql (530.43µs)10892026/09/20 10:36:47 goose: up to current file version: 21090--- PASS: TestService_ReadAuthMiddleware (0.74s)1091=== CONT TestService_cleanupPendingClosuresHandler1092=== NAME TestClientIntegration1093 client_integration_test.go:286: Created store path: /build/TestClientIntegration2848259520/002/store/hkyfrhlcfs4f0wfmc6yrfq2q4dbhpbs4-test-file.txt10942026/09/20 10:36:47 OK 20241026095416_initial_model.sql (7.92ms)10952026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)10962026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.17ms)10972026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)10982026/09/20 10:36:47 OK 20260905000000_add_claims.sql (2.82ms)10992026/09/20 10:36:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11002026/09/20 10:36:47 INFO Received uploads request method=POST path=/api/pending_closures11012026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.4ms)11022026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000011032026/09/20 10:36:47 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"11042026/09/20 10:36:47 WARN mTLS auth: bound subjects configured but subject DN unavailable11052026/09/20 10:36:47 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1106--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.76s)1107=== CONT TestOrphanedObjectsGCStressTest11082026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.5ms)11092026/09/20 10:36:47 OK 2_object_stats_trigger.sql (960.69µs)11102026/09/20 10:36:47 goose: up to current file version: 211112026/09/20 10:36:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11122026/09/20 10:36:47 INFO Uploading a44xvrpahc2p5n13k64bzkw06lzabvnc-test-script (136B)11132026/09/20 10:36:47 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11142026/09/20 10:36:47 WARN Failed to register uploaded object key=a44xvrpahc2p5n13k64bzkw06lzabvnc.ls error="server returned 404: 404 page not found\n"11152026/09/20 10:36:47 WARN Failed to register uploaded object key=log/pj8ya7rwh0qmkpyzsa95x9sq0ni09rm9-test-script.drv error="server returned 404: 404 page not found\n"11162026/09/20 10:36:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11172026/09/20 10:36:47 INFO Signed narinfos id=1 count=111182026/09/20 10:36:47 INFO Uploading 1 narinfos11192026/09/20 10:36:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11202026/09/20 10:36:47 WARN Failed to register uploaded object key=a44xvrpahc2p5n13k64bzkw06lzabvnc.narinfo error="server returned 404: 404 page not found\n"11212026/09/20 10:36:47 INFO Aborted multipart uploads count=011222026/09/20 10:36:47 WARN Force mode enabled - objects will be deleted immediately without grace period11232026/09/20 10:36:47 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=011242026/09/20 10:36:47 INFO Completed upload id=111252026/09/20 10:36:47 INFO Upload complete. (89ms)1126--- PASS: TestReadProxyInvalidPath (0.81s)1127=== CONT TestUploadHandlersRejectOversizedBody1128=== NAME TestClientWithDependencies1129 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2149776402/001/store) requires matching store prefix11302026/09/20 10:36:47 INFO Vacuumed table table=pending_closures11312026/09/20 10:36:47 INFO Vacuumed table table=pending_objects11322026/09/20 10:36:47 INFO Vacuumed table table=multipart_uploads11332026/09/20 10:36:47 INFO Vacuumed table table=closures11342026/09/20 10:36:47 INFO Vacuumed table table=objects1135--- PASS: TestClientWithDependencies (0.82s)1136=== CONT TestOrphanedObjectsGC11372026/09/20 10:36:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1138--- PASS: TestGCMetrics (0.82s)1139=== CONT TestUploadHandlersRejectInvalidKeys1140=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1141=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1142=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1143=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1144=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1145=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1146=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1147=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1148=== CONT TestIsValidUploadKey1149=== RUN TestIsValidUploadKey/narinfo1150=== PAUSE TestIsValidUploadKey/narinfo1151=== RUN TestIsValidUploadKey/nar_zst1152=== PAUSE TestIsValidUploadKey/nar_zst1153=== RUN TestIsValidUploadKey/nar_xz1154=== PAUSE TestIsValidUploadKey/nar_xz1155=== RUN TestIsValidUploadKey/nar_plain1156=== PAUSE TestIsValidUploadKey/nar_plain1157=== RUN TestIsValidUploadKey/listing1158=== PAUSE TestIsValidUploadKey/listing1159=== RUN TestIsValidUploadKey/build_log1160=== PAUSE TestIsValidUploadKey/build_log1161=== RUN TestIsValidUploadKey/build_log_home-manager_file1162=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1163=== RUN TestIsValidUploadKey/build_log_plus_in_name1164=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1165=== RUN TestIsValidUploadKey/build_log_question_mark1166=== PAUSE TestIsValidUploadKey/build_log_question_mark1167=== RUN TestIsValidUploadKey/build_log_equals1168=== PAUSE TestIsValidUploadKey/build_log_equals1169=== RUN TestIsValidUploadKey/realisation1170=== PAUSE TestIsValidUploadKey/realisation1171=== RUN TestIsValidUploadKey/realisation_plus_in_output1172=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1173=== RUN TestIsValidUploadKey/nix-cache-info1174=== PAUSE TestIsValidUploadKey/nix-cache-info1175=== RUN TestIsValidUploadKey/index.html1176=== PAUSE TestIsValidUploadKey/index.html1177=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1178=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1179=== RUN TestIsValidUploadKey/nar_key,_narinfo_type11802026/09/20 10:36:47 INFO lead: released remote=192.0.2.1:123411812026/09/20 10:36:47 INFO Received uploads request method=POST path=/api/pending_closures1182=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1183=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1184--- PASS: TestGCBugBareHashReferences (0.86s)1185=== CONT TestObjectStatsTrigger11862026-09-20 10:36:47.533 UTC [853] ERROR: relation "goose_db_version" does not exist at character 3611872026-09-20 10:36:47.533 UTC [853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11882026/09/20 10:36:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11892026/09/20 10:36:47 INFO Uploading hkyfrhlcfs4f0wfmc6yrfq2q4dbhpbs4-test-file.txt (152B)1190=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1191=== RUN TestIsValidUploadKey/traversal1192=== PAUSE TestIsValidUploadKey/traversal1193=== RUN TestIsValidUploadKey/traversal_nar1194=== PAUSE TestIsValidUploadKey/traversal_nar1195=== RUN TestIsValidUploadKey/absolute11962026/09/20 10:36:47 OK 20241026095416_initial_model.sql (8.94ms)11972026-09-20 10:36:47.547 UTC [855] ERROR: relation "goose_db_version" does not exist at character 3611982026-09-20 10:36:47.547 UTC [855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11992026-09-20 10:36:47.547 UTC [856] ERROR: relation "goose_db_version" does not exist at character 3612002026-09-20 10:36:47.547 UTC [856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12012026/09/20 10:36:47 INFO lead: acquired remote=192.0.2.1:12341202=== PAUSE TestIsValidUploadKey/absolute1203=== RUN TestIsValidUploadKey/empty_key1204=== PAUSE TestIsValidUploadKey/empty_key1205=== RUN TestIsValidUploadKey/unknown_type1206=== PAUSE TestIsValidUploadKey/unknown_type1207=== CONT TestProxyWriteTimeout1208=== RUN TestProxyWriteTimeout/narinfo1209=== PAUSE TestProxyWriteTimeout/narinfo1210=== RUN TestProxyWriteTimeout/1_GiB_nar1211=== PAUSE TestProxyWriteTimeout/1_GiB_nar1212=== RUN TestProxyWriteTimeout/10_GiB_nar1213=== PAUSE TestProxyWriteTimeout/10_GiB_nar1214--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.93s)1215=== CONT TestMultipartCleanup1216=== RUN TestProxyWriteTimeout/unknown_size1217=== PAUSE TestProxyWriteTimeout/unknown_size1218=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12192026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)12202026/09/20 10:36:47 INFO lead: released remote=192.0.2.1:12341221--- PASS: TestLeadElectsOneAndHandsOver (0.94s)1222=== CONT TestServerTLSConfig1223=== RUN TestServerTLSConfig/no_client_CA1224=== PAUSE TestServerTLSConfig/no_client_CA1225=== RUN TestServerTLSConfig/missing_CA_file1226=== PAUSE TestServerTLSConfig/missing_CA_file12272026/09/20 10:36:47 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1228=== RUN TestServerTLSConfig/not_a_PEM_file1229=== PAUSE TestServerTLSConfig/not_a_PEM_file1230=== CONT TestSkippedUploadsHandler12312026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.17ms)12322026/09/20 10:36:47 INFO Client skipped oversized paths paths=3 nar_bytes=500000000012332026-09-20 10:36:47.616 UTC [859] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-20 10:36:47.616 UTC [859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026-09-20 10:36:47.616 UTC [861] ERROR: relation "goose_db_version" does not exist at character 3612362026-09-20 10:36:47.616 UTC [861] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12372026/09/20 10:36:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12382026/09/20 10:36:47 WARN Failed to register uploaded object key=hkyfrhlcfs4f0wfmc6yrfq2q4dbhpbs4.ls error="server returned 404: 404 page not found\n"12392026/09/20 10:36:47 OK 20241026095416_initial_model.sql (8.28ms)12402026/09/20 10:36:47 INFO Signed narinfos id=1 count=112412026/09/20 10:36:47 INFO Uploading 1 narinfos1242--- PASS: TestSkippedUploadsHandler (0.00s)1243=== CONT TestService_readinessHandler12442026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)12452026/09/20 10:36:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1246=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts12472026/09/20 10:36:47 WARN Failed to register uploaded object key=hkyfrhlcfs4f0wfmc6yrfq2q4dbhpbs4.narinfo error="server returned 404: 404 page not found\n"1248=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts12492026/09/20 10:36:47 OK 20241026095416_initial_model.sql (99.8ms)1250=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1251=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure12522026/09/20 10:36:47 OK 20260905000000_add_claims.sql (90.42ms)1253=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1254=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1255=== CONT TestParseSize1256--- PASS: TestParseSize (0.00s)1257=== CONT TestMetricsInventory12582026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)12592026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)12602026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.56ms)12612026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000012622026-09-20 10:36:47.722 UTC [867] ERROR: relation "goose_db_version" does not exist at character 3612632026-09-20 10:36:47.722 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12642026/09/20 10:36:47 INFO Completed upload id=112652026-09-20 10:36:47.723 UTC [866] ERROR: relation "goose_db_version" does not exist at character 3612662026-09-20 10:36:47.723 UTC [866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12672026/09/20 10:36:47 INFO Upload complete. (268ms)12682026-09-20 10:36:47.723 UTC [868] ERROR: relation "goose_db_version" does not exist at character 3612692026-09-20 10:36:47.723 UTC [868] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12702026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.79ms)12712026/09/20 10:36:47 OK 20241026095416_initial_model.sql (9.37ms)12722026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.62ms)12732026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.27ms)12742026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)12752026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.66ms)12762026/09/20 10:36:47 goose: up to current file version: 212772026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (4.78ms)12782026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (6.28ms)12792026/09/20 10:36:47 OK 20241026095416_initial_model.sql (13.07ms)12802026/09/20 10:36:47 OK 20251218171726_add_pins.sql (4.83ms)12812026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)12822026/09/20 10:36:47 OK 20260905000000_add_claims.sql (15.58ms)12832026/09/20 10:36:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12842026/09/20 10:36:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1285--- PASS: TestService_NativeMTLS (1.07s)1286=== CONT TestGCTaskStore_Fail1287--- PASS: TestGCTaskStore_Fail (0.00s)1288=== CONT TestNARDeduplicationMetadataUploadBug12892026/09/20 10:36:47 OK 20241026095416_initial_model.sql (17.1ms)12902026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (15.35ms)12912026/09/20 10:36:47 OK 20241026095416_initial_model.sql (19.21ms)12922026/09/20 10:36:47 OK 20260905000000_add_claims.sql (16.21ms)12932026/09/20 10:36:47 OK 20251218171726_add_pins.sql (13.44ms)12942026/09/20 10:36:47 OK 20241026095416_initial_model.sql (17.32ms)12952026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)12962026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (4.48ms)12972026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000012982026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)12992026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)13002026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.73ms)13012026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (4.54ms)13022026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000013032026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.03ms)13042026/09/20 10:36:47 OK 20251218171726_add_pins.sql (3.13ms)13052026/09/20 10:36:47 OK 20251218171726_add_pins.sql (3.31ms)13062026/09/20 10:36:47 OK 20251218171726_add_pins.sql (3.42ms)13072026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (6.25ms)13082026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.65ms)13092026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.84ms)13102026/09/20 10:36:47 goose: up to current file version: 213112026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)13122026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (4.23ms)13132026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000013142026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.51ms)13152026/09/20 10:36:47 goose: up to current file version: 213162026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)13172026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)13182026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.85ms)13192026/09/20 10:36:47 OK 20260905000000_add_claims.sql (4.19ms)13202026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.85ms)13212026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.04ms)13222026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.09ms)13232026/09/20 10:36:47 INFO All 1 paths already cached13242026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.58ms)13252026/09/20 10:36:47 goose: up to current file version: 21326=== NAME TestClientIntegration1327 client_integration_test.go:312: Retrieved narinfo from S3:13282026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.41ms)1329 StorePath: /build/TestClientIntegration2848259520/002/store/hkyfrhlcfs4f0wfmc6yrfq2q4dbhpbs4-test-file.txt13302026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000001331 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1332 Compression: zstd1333 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113342026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.73ms)1335 NarSize: 15213362026/09/20 10:36:47 goose: successfully migrated database to version: 202609200000001337 References: 1338 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113392026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.35ms)13402026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000013412026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.62ms)13422026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000013432026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.04ms)1344 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1345 client_integration_test.go:313: Decompressed .ls content (64 bytes):1346 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1347 client_integration_test.go:316: Testing garbage collection...13482026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.83ms)13492026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.97ms)13502026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.13ms)13512026/09/20 10:36:47 goose: up to current file version: 213522026/09/20 10:36:47 OK 1_commit_pending_closure.sql (4.22ms)13532026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.64ms)13542026/09/20 10:36:47 goose: up to current file version: 213552026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.79ms)13562026/09/20 10:36:47 goose: up to current file version: 213572026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.01ms)13582026/09/20 10:36:47 goose: up to current file version: 21359--- PASS: TestService_Rustfstest (1.09s)1360=== CONT TestService_healthCheckHandler1361=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1362=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1363=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1364=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1365=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1366=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1367=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1368=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1369=== CONT TestCreatePendingClosureRejectsOversizedNAR13702026/09/20 10:36:47 INFO Received uploads request method=POST path=/api/pending_closures1371--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1372=== CONT TestGracefulShutdownDrainsInflight13732026/09/20 10:36:47 INFO Starting HTTP server address=127.0.0.1:3866713742026/09/20 10:36:47 INFO Shutdown signal received, draining in-flight requests timeout=10s1375=== NAME TestPinProtectsFromGC1376 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2113488619/001/store/yr0plq73kx90lwm0207mr2szqm9c0xvg-pinned-file.txt1377 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2113488619/001/store/smlfnpd9zap6kfjis539v3x7gjahzfbn-unpinned-file.txt13782026/09/20 10:36:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures13792026/09/20 10:36:47 INFO Garbage collection started13802026/09/20 10:36:47 INFO Aborted multipart uploads count=013812026-09-20 10:36:47.813 UTC [947] ERROR: relation "goose_db_version" does not exist at character 3613822026-09-20 10:36:47.813 UTC [947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13832026/09/20 10:36:47 WARN Force mode enabled - objects will be deleted immediately without grace period13842026/09/20 10:36:47 OK 20241026095416_initial_model.sql (8.4ms)13852026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)13862026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.79ms)13872026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)13882026/09/20 10:36:47 OK 20260905000000_add_claims.sql (2.56ms)13892026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (1.97ms)13902026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000013912026-09-20 10:36:47.842 UTC [966] ERROR: relation "goose_db_version" does not exist at character 3613922026-09-20 10:36:47.842 UTC [966] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13932026/09/20 10:36:47 OK 1_commit_pending_closure.sql (1.97ms)1394--- PASS: TestReadProxyNarStreaming (1.16s)1395=== CONT TestCacheConfigHandlerMaxNarSize1396--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1397=== CONT TestGenerateLandingPage13982026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.45ms)13992026/09/20 10:36:47 goose: up to current file version: 21400--- PASS: TestGenerateLandingPage (0.00s)1401=== CONT TestReadProxyRangeRequest14022026/09/20 10:36:47 OK 20241026095416_initial_model.sql (8.42ms)14032026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (963.22µs)14042026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.72ms)14052026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (2.86ms)14062026-09-20 10:36:47.865 UTC [987] ERROR: relation "goose_db_version" does not exist at character 3614072026-09-20 10:36:47.865 UTC [987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1408--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1409=== CONT TestGCTaskStore_PhaseUpdates1410--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1411=== CONT TestPresignedUploadRegisteredBeforeCommit14122026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.34ms)14132026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.38ms)14142026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000014152026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.22ms)14162026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.67ms)14172026/09/20 10:36:47 goose: up to current file version: 214182026/09/20 10:36:47 OK 20241026095416_initial_model.sql (7.91ms)14192026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)14202026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.4ms)14212026/09/20 10:36:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14222026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)14232026/09/20 10:36:47 OK 20260905000000_add_claims.sql (2.88ms)14242026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (10.34ms)14252026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000014262026/09/20 10:36:47 OK 1_commit_pending_closure.sql (3.2ms)1427=== NAME TestClientMultipleUploads1428 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1542580838/001/store/i9zpqyy0acz00c1l4g3g05jlmc9dx70k-test-file-0.txt14292026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.76ms)14302026/09/20 10:36:47 goose: up to current file version: 21431=== RUN TestService_RequireScope_OIDC/builder_may_write1432=== PAUSE TestService_RequireScope_OIDC/builder_may_write1433=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1434=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1435=== RUN TestService_RequireScope_OIDC/ops_may_admin1436=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1437=== RUN TestService_RequireScope_OIDC/ops_may_not_write1438=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1439=== RUN TestService_RequireScope_OIDC/reader_may_not_write1440=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1441=== RUN TestService_RequireScope_OIDC/static_token_may_admin1442=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1443=== RUN TestService_RequireScope_OIDC/static_token_may_write1444=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1445=== RUN TestService_RequireScope_OIDC/reader_may_read1446=== PAUSE TestService_RequireScope_OIDC/reader_may_read1447=== RUN TestService_RequireScope_OIDC/writer_implies_read1448=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1449=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1450=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1451=== CONT TestReadProxyDisabled14522026/09/20 10:36:47 INFO Received uploads request method=POST path=/api/pending_closures14532026/09/20 10:36:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14542026/09/20 10:36:47 INFO Uploading yr0plq73kx90lwm0207mr2szqm9c0xvg-pinned-file.txt (128B)14552026/09/20 10:36:47 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14562026/09/20 10:36:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14572026/09/20 10:36:47 WARN Failed to register uploaded object key=yr0plq73kx90lwm0207mr2szqm9c0xvg.ls error="server returned 404: 404 page not found\n"14582026/09/20 10:36:47 INFO Signed narinfos id=1 count=114592026/09/20 10:36:47 INFO Uploading 1 narinfos1460--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.76s)1461=== CONT TestCompletedNarNotReofferedAcrossClosures14622026/09/20 10:36:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14632026/09/20 10:36:47 WARN Failed to register uploaded object key=yr0plq73kx90lwm0207mr2szqm9c0xvg.narinfo error="server returned 404: 404 page not found\n"14642026-09-20 10:36:47.936 UTC [1113] ERROR: relation "goose_db_version" does not exist at character 3614652026-09-20 10:36:47.936 UTC [1113] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1466=== NAME TestClientMultipleUploads1467 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1542580838/001/store/zqaw6494fndjn5hd6h0hbjz8kkz3lyb7-test-file-1.txt14682026/09/20 10:36:47 INFO Completed upload id=114692026/09/20 10:36:47 INFO Upload complete. (103ms)14702026/09/20 10:36:47 OK 20241026095416_initial_model.sql (8.78ms)14712026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)14722026/09/20 10:36:47 OK 20251218171726_add_pins.sql (2.84ms)1473--- PASS: TestReadProxyNarinfo (0.74s)1474=== CONT TestCompleteMultipartUpload_ErrorButObjectExists14752026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)14762026-09-20 10:36:47.962 UTC [1135] ERROR: relation "goose_db_version" does not exist at character 3614772026-09-20 10:36:47.962 UTC [1135] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14782026/09/20 10:36:47 OK 20260905000000_add_claims.sql (5.26ms)14792026/09/20 10:36:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14802026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (3.51ms)14812026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000014822026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.5ms)1483=== NAME TestClientCADerivations1484 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations906550911/001/store/6c7zr8hfg23hbwn8fv2wbd4kvbm84ac2-ca-test14852026/09/20 10:36:47 OK 2_object_stats_trigger.sql (2.11ms)14862026/09/20 10:36:47 goose: up to current file version: 21487=== NAME TestClientMultipleUploads1488 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1542580838/001/store/p9hy9z69dbrxjpkv67s846czjmra0wdl-test-file-2.txt14892026/09/20 10:36:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14902026/09/20 10:36:47 OK 20241026095416_initial_model.sql (11.14ms)14912026/09/20 10:36:47 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)14922026/09/20 10:36:47 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1493--- PASS: TestCompleteMultipartUnregistered (0.73s)1494=== CONT TestReadRedirectKeepsNarinfoProxied14952026/09/20 10:36:47 OK 20251218171726_add_pins.sql (3.14ms)14962026/09/20 10:36:47 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)14972026/09/20 10:36:47 OK 20260905000000_add_claims.sql (3.7ms)14982026/09/20 10:36:47 OK 20260920000000_drop_claims.sql (2.37ms)14992026/09/20 10:36:47 goose: successfully migrated database to version: 2026092000000015002026/09/20 10:36:47 OK 1_commit_pending_closure.sql (2.21ms)15012026/09/20 10:36:47 OK 2_object_stats_trigger.sql (1.55ms)15022026/09/20 10:36:47 goose: up to current file version: 215032026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures1504=== NAME TestClientCADerivations1505 client_ca_test.go:139: Found 1 dependencies (including self)15062026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15072026/09/20 10:36:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15082026-09-20 10:36:48.022 UTC [1267] ERROR: relation "goose_db_version" does not exist at character 3615092026-09-20 10:36:48.022 UTC [1267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15102026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15112026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15122026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15132026-09-20 10:36:48.035 UTC [1270] ERROR: relation "goose_db_version" does not exist at character 3615142026-09-20 10:36:48.035 UTC [1270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15152026/09/20 10:36:48 OK 20241026095416_initial_model.sql (9.93ms)15162026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)15172026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15182026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.96ms)15192026/09/20 10:36:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15202026/09/20 10:36:48 INFO Uploading smlfnpd9zap6kfjis539v3x7gjahzfbn-unpinned-file.txt (128B)15212026/09/20 10:36:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15222026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)15232026/09/20 10:36:48 OK 20241026095416_initial_model.sql (8.38ms)15242026/09/20 10:36:48 OK 20260905000000_add_claims.sql (2.8ms)15252026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)15262026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15272026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (1.71ms)15282026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000015292026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.52ms)15302026/09/20 10:36:48 OK 1_commit_pending_closure.sql (1.93ms)15312026/09/20 10:36:48 INFO Received cleanup request method=DELETE path=/api/pending_closures15322026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15332026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.28ms)15342026/09/20 10:36:48 goose: up to current file version: 215352026/09/20 10:36:48 WARN Failed to register uploaded object key=smlfnpd9zap6kfjis539v3x7gjahzfbn.ls error="server returned 404: 404 page not found\n"15362026/09/20 10:36:48 INFO Signed narinfos id=2 count=115372026/09/20 10:36:48 INFO Uploading 1 narinfos15382026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (3.58ms)15392026/09/20 10:36:48 INFO Aborted multipart uploads count=015402026-09-20 10:36:48.060 UTC [1342] ERROR: relation "goose_db_version" does not exist at character 3615412026-09-20 10:36:48.060 UTC [1342] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15422026/09/20 10:36:48 OK 20260905000000_add_claims.sql (3.18ms)15432026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15442026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15452026/09/20 10:36:48 WARN Failed to register uploaded object key=smlfnpd9zap6kfjis539v3x7gjahzfbn.narinfo error="server returned 404: 404 page not found\n"15462026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (2.16ms)15472026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000015482026/09/20 10:36:48 INFO Completed upload id=215492026/09/20 10:36:48 INFO Upload complete. (91ms)15502026/09/20 10:36:48 OK 1_commit_pending_closure.sql (1.39ms)15512026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.04ms)15522026/09/20 10:36:48 goose: up to current file version: 215532026/09/20 10:36:48 INFO Received cleanup request method=DELETE path=/api/pending_closures15542026/09/20 10:36:48 INFO Aborted multipart uploads count=115552026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15562026-09-20 10:36:48.073 UTC [853] ERROR: Closure does not exist: id=115572026-09-20 10:36:48.073 UTC [853] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE15582026-09-20 10:36:48.073 UTC [853] STATEMENT: -- name: CommitPendingClosure :exec1559 SELECT commit_pending_closure($1::bigint)1560 1561--- PASS: TestService_cleanupPendingClosuresHandler (0.66s)1562=== CONT TestRedundantMultipartUpload15632026/09/20 10:36:48 OK 20241026095416_initial_model.sql (7.57ms)15642026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)15652026/09/20 10:36:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15662026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.18ms)15672026-09-20 10:36:48.080 UTC [1367] ERROR: relation "goose_db_version" does not exist at character 3615682026-09-20 10:36:48.080 UTC [1367] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15692026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)15702026/09/20 10:36:48 OK 20260905000000_add_claims.sql (2.71ms)15712026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15722026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (1.77ms)15732026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000015742026/09/20 10:36:48 OK 1_commit_pending_closure.sql (1.78ms)15752026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.2ms)15762026/09/20 10:36:48 goose: up to current file version: 215772026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15782026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures15792026/09/20 10:36:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15802026/09/20 10:36:48 INFO Uploading p9hy9z69dbrxjpkv67s846czjmra0wdl-test-file-2.txt (160B)15812026/09/20 10:36:48 INFO Uploading i9zpqyy0acz00c1l4g3g05jlmc9dx70k-test-file-0.txt (160B)15822026/09/20 10:36:48 INFO Uploading zqaw6494fndjn5hd6h0hbjz8kkz3lyb7-test-file-1.txt (160B)15832026/09/20 10:36:48 OK 20241026095416_initial_model.sql (9.47ms)15842026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)15852026/09/20 10:36:48 INFO Received create pin request method=POST path=/api/pins/myapp15862026/09/20 10:36:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15872026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.6ms)15882026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15892026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15902026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15912026/09/20 10:36:48 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2113488619/001/store/yr0plq73kx90lwm0207mr2szqm9c0xvg-pinned-file.txt narinfo_key=yr0plq73kx90lwm0207mr2szqm9c0xvg.narinfo15922026/09/20 10:36:48 WARN Failed to register uploaded object key=p9hy9z69dbrxjpkv67s846czjmra0wdl.ls error="server returned 404: 404 page not found\n"15932026/09/20 10:36:48 WARN Failed to register uploaded object key=i9zpqyy0acz00c1l4g3g05jlmc9dx70k.ls error="server returned 404: 404 page not found\n"15942026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)15952026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15962026/09/20 10:36:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures15972026/09/20 10:36:48 WARN Failed to register uploaded object key=zqaw6494fndjn5hd6h0hbjz8kkz3lyb7.ls error="server returned 404: 404 page not found\n"15982026/09/20 10:36:48 INFO Signed narinfos id=1 count=115992026/09/20 10:36:48 INFO Garbage collection started16002026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16012026/09/20 10:36:48 INFO Signed narinfos id=2 count=116022026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16032026/09/20 10:36:48 INFO Signed narinfos id=3 count=116042026/09/20 10:36:48 INFO Uploading 3 narinfos16052026/09/20 10:36:48 OK 20260905000000_add_claims.sql (2.53ms)16062026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (1.86ms)16072026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000016082026/09/20 10:36:48 WARN Failed to register uploaded object key=zqaw6494fndjn5hd6h0hbjz8kkz3lyb7.narinfo error="server returned 404: 404 page not found\n"16092026/09/20 10:36:48 WARN Failed to register uploaded object key=i9zpqyy0acz00c1l4g3g05jlmc9dx70k.narinfo error="server returned 404: 404 page not found\n"16102026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16112026/09/20 10:36:48 WARN Failed to register uploaded object key=p9hy9z69dbrxjpkv67s846czjmra0wdl.narinfo error="server returned 404: 404 page not found\n"16122026/09/20 10:36:48 OK 1_commit_pending_closure.sql (2.01ms)16132026/09/20 10:36:48 OK 2_object_stats_trigger.sql (731.89µs)16142026/09/20 10:36:48 goose: up to current file version: 216152026/09/20 10:36:48 INFO Completed upload id=216162026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16172026/09/20 10:36:48 INFO Completed upload id=316182026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16192026/09/20 10:36:48 INFO Aborted multipart uploads count=016202026/09/20 10:36:48 INFO Completed upload id=116212026/09/20 10:36:48 INFO Upload complete. (111ms)16222026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures1623=== NAME TestClientMultipleUploads1624 client_integration_test.go:369: Uploaded 3 paths in 143.732942ms1625--- PASS: TestResurrectedObjectNotDeleted (0.72s)1626=== CONT TestReadRedirectNar16272026/09/20 10:36:48 WARN Force mode enabled - objects will be deleted immediately without grace period16282026/09/20 10:36:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16292026/09/20 10:36:48 INFO Uploading 6c7zr8hfg23hbwn8fv2wbd4kvbm84ac2-ca-test (144B)1630--- PASS: TestClientMultipleUploads (1.45s)1631=== CONT TestReadRedirectUsesPublicS3URL16322026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16332026/09/20 10:36:48 WARN Failed to register uploaded object key=log/bwjkaql8ygmcvfcv4dfxjrfy51100hbm-ca-test.drv error="server returned 404: 404 page not found\n"16342026/09/20 10:36:48 WARN Failed to register uploaded object key=6c7zr8hfg23hbwn8fv2wbd4kvbm84ac2.ls error="server returned 404: 404 page not found\n"16352026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16362026/09/20 10:36:48 INFO Signed narinfos id=1 count=116372026/09/20 10:36:48 INFO Uploading 1 narinfos16382026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16392026/09/20 10:36:48 WARN Failed to register uploaded object key=6c7zr8hfg23hbwn8fv2wbd4kvbm84ac2.narinfo error="server returned 404: 404 page not found\n"16402026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures16412026/09/20 10:36:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16422026/09/20 10:36:48 INFO Uploading 2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx-shared-dep (136B)16432026/09/20 10:36:48 INFO Completed upload id=116442026/09/20 10:36:48 INFO Upload complete. (108ms)1645=== NAME TestClientCADerivations1646 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations906550911/001/store/6c7zr8hfg23hbwn8fv2wbd4kvbm84ac2-ca-test1647 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1648 Compression: zstd1649 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1650 NarSize: 1441651 References: 1652 Deriver: /build/TestClientCADerivations906550911/001/store/bwjkaql8ygmcvfcv4dfxjrfy51100hbm-ca-test.drv1653 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1654 client_ca_test.go:185: Checking for realisation files in S3...16552026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1656 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1657 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16582026/09/20 10:36:48 WARN Failed to register uploaded object key=2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx.ls error="server returned 404: 404 page not found\n"16592026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16602026/09/20 10:36:48 INFO Signed narinfos id=2 count=116612026/09/20 10:36:48 INFO Uploading 1 narinfos16622026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16632026/09/20 10:36:48 WARN Failed to register uploaded object key=2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx.narinfo error="server returned 404: 404 page not found\n"16642026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures16652026-09-20 10:36:48.168 UTC [1463] ERROR: relation "goose_db_version" does not exist at character 3616662026-09-20 10:36:48.168 UTC [1463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16672026/09/20 10:36:48 INFO Completed upload id=216682026/09/20 10:36:48 INFO Upload complete. (107ms)16692026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures16702026/09/20 10:36:48 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16712026/09/20 10:36:48 INFO Uploading sz6la061wmqjlzc0bbq1z3inqvypvkbx-top (224B)16722026/09/20 10:36:48 INFO Uploading 2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx-shared-dep (136B)16732026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/0jf53ljd0kck7098n976v33khky008yj8bsz14p3z4fjm28lrv22.nar.zst error="server returned 404: 404 page not found\n"16742026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16752026/09/20 10:36:48 WARN Failed to register uploaded object key=sz6la061wmqjlzc0bbq1z3inqvypvkbx.ls error="server returned 404: 404 page not found\n"16762026/09/20 10:36:48 WARN Failed to register uploaded object key=2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx.ls error="server returned 404: 404 page not found\n"16772026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16782026/09/20 10:36:48 INFO Signed narinfos id=1 count=116792026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16802026/09/20 10:36:48 INFO Signed narinfos id=3 count=116812026/09/20 10:36:48 INFO Uploading 2 narinfos16822026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16832026/09/20 10:36:48 WARN Failed to register uploaded object key=sz6la061wmqjlzc0bbq1z3inqvypvkbx.narinfo error="server returned 404: 404 page not found\n"16842026/09/20 10:36:48 WARN readiness check failed error="closed pool"1685--- PASS: TestService_readinessHandler (0.57s)16862026/09/20 10:36:48 WARN Failed to register uploaded object key=2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx.narinfo error="server returned 404: 404 page not found\n"1687=== CONT TestReadProxyConditionalGet16882026/09/20 10:36:48 INFO Completed upload id=116892026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16902026/09/20 10:36:48 INFO Completed upload id=316912026/09/20 10:36:48 INFO Upload complete. (268ms)1692=== NAME TestClientSharedPathCommittedMidPush1693 client_integration_test.go:680: Retrieved narinfo from S3:1694 StorePath: /build/TestClientSharedPathCommittedMidPush3157463750/001/store/2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx-shared-dep1695 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1696 Compression: zstd1697 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821698 NarSize: 1361699 References: 1700 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17012026/09/20 10:36:48 OK 20241026095416_initial_model.sql (9.94ms)1702 client_integration_test.go:680: Retrieved narinfo from S3:1703 StorePath: /build/TestClientSharedPathCommittedMidPush3157463750/001/store/sz6la061wmqjlzc0bbq1z3inqvypvkbx-top1704 URL: nar/0jf53ljd0kck7098n976v33khky008yj8bsz14p3z4fjm28lrv22.nar.zst1705 Compression: zstd1706 NarHash: sha256:0jf53ljd0kck7098n976v33khky008yj8bsz14p3z4fjm28lrv221707 NarSize: 2241708 References: /build/TestClientSharedPathCommittedMidPush3157463750/001/store/2wpd2fp8z8n7g47fs2jzwir6bi2ydyxx-shared-dep1709 CA: text:sha256:1902xakgfmc5c03q6mm33q4rhh98wrbpb26fn9pzv1qd8x9lds3617102026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)17112026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.74ms)17122026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)1713--- PASS: TestClientSharedPathCommittedMidPush (1.53s)1714=== CONT TestReadProxyRootRedirectsToIndexHTML17152026/09/20 10:36:48 OK 20260905000000_add_claims.sql (3.48ms)17162026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (2.84ms)17172026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000017182026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures17192026/09/20 10:36:48 OK 1_commit_pending_closure.sql (2.26ms)17202026/09/20 10:36:48 OK 2_object_stats_trigger.sql (756.69µs)17212026/09/20 10:36:48 goose: up to current file version: 217222026-09-20 10:36:48.220 UTC [1505] ERROR: relation "goose_db_version" does not exist at character 3617232026-09-20 10:36:48.220 UTC [1505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17242026-09-20 10:36:48.231 UTC [1548] ERROR: relation "goose_db_version" does not exist at character 3617252026-09-20 10:36:48.231 UTC [1548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17262026/09/20 10:36:48 OK 20241026095416_initial_model.sql (8.42ms)17272026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)17282026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.37ms)17292026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)17302026/09/20 10:36:48 OK 20241026095416_initial_model.sql (8.56ms)17312026/09/20 10:36:48 OK 20260905000000_add_claims.sql (3.09ms)17322026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)17332026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (2.08ms)17342026/09/20 10:36:48 goose: successfully migrated database to version: 202609200000001735--- PASS: TestObjectStatsTrigger (0.72s)1736=== CONT TestReadProxyHead17372026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.9ms)17382026/09/20 10:36:48 OK 1_commit_pending_closure.sql (2.18ms)17392026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.46ms)17402026/09/20 10:36:48 goose: up to current file version: 217412026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)17422026/09/20 10:36:48 OK 20260905000000_add_claims.sql (3.29ms)17432026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (3.02ms)17442026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000017452026/09/20 10:36:48 OK 1_commit_pending_closure.sql (2.39ms)17462026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.96ms)17472026/09/20 10:36:48 goose: up to current file version: 217482026-09-20 10:36:48.283 UTC [1661] ERROR: relation "goose_db_version" does not exist at character 3617492026-09-20 10:36:48.283 UTC [1661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1750--- PASS: TestMetricsInventory (0.57s)1751=== CONT TestGCTaskStore_CompletedAllowsNewTask1752--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1753=== CONT TestCacheConfigHandler/full_config,_no_issuer17542026/09/20 10:36:48 INFO Received cleanup request method=DELETE path=/api/pending_closures1755=== CONT TestCacheConfigHandler/no_signing_keys1756=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1757=== CONT TestCacheConfigHandler/no_cache_url_configured1758--- PASS: TestCacheConfigHandler (0.00s)1759 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1760 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1761 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1762 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1763=== CONT TestResolveDBConnectionString/flag_wins1764=== CONT TestResolveDBConnectionString/nothing_configured1765=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1766=== CONT TestResolveDBConnectionString/missing_file_is_an_error1767=== CONT TestResolveDBConnectionString/file_when_flag_empty1768=== CONT TestClientErrorHandling/InvalidStorePath1769--- PASS: TestResolveDBConnectionString (0.01s)1770 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1771 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1772 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1773 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1774 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17752026/09/20 10:36:48 INFO Aborted multipart uploads count=117762026/09/20 10:36:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17772026-09-20 10:36:48.299 UTC [1708] ERROR: relation "goose_db_version" does not exist at character 3617782026-09-20 10:36:48.299 UTC [1708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17792026/09/20 10:36:48 OK 20241026095416_initial_model.sql (15.58ms)17802026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)1781--- PASS: TestMultipartCleanup (0.70s)1782=== CONT TestClientErrorHandling/ServerNotAvailable1783--- PASS: TestService_healthCheckHandler (0.54s)1784=== CONT TestClientErrorHandling/InvalidAuthToken17852026/09/20 10:36:48 OK 20251218171726_add_pins.sql (3.46ms)17862026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)1787=== NAME TestClientCADerivations1788 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1789 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1790 error: binary cache 's3://bucket24?endpoint=http://localhost:39071&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations906550911/001/store'1791 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117922026/09/20 10:36:48 OK 20241026095416_initial_model.sql (13.12ms)17932026/09/20 10:36:48 OK 20260905000000_add_claims.sql (3.72ms)17942026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)17952026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (3.02ms)17962026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000017972026/09/20 10:36:48 OK 20251218171726_add_pins.sql (3.01ms)17982026/09/20 10:36:48 OK 1_commit_pending_closure.sql (2.32ms)1799--- PASS: TestClientCADerivations (1.65s)1800=== CONT TestIsValidCachePath/narinfo1801=== CONT TestIsValidCachePath/index.html1802=== CONT TestIsValidCachePath/short_hash1803=== CONT TestIsValidCachePath/invalid_char_u18042026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.52ms)1805=== CONT TestIsValidCachePath/invalid_char_e18062026/09/20 10:36:48 goose: up to current file version: 21807=== CONT TestIsValidCachePath/random_path1808=== CONT TestIsValidCachePath/traversal_in_middle1809=== CONT TestIsValidCachePath/wrong_extension1810=== CONT TestIsValidCachePath/leading_slash1811=== CONT TestIsValidCachePath/traversal_parent1812=== CONT TestIsValidCachePath/empty1813=== CONT TestIsValidCachePath/nar_uncompressed1814=== CONT TestIsValidCachePath/nix-cache-info1815=== CONT TestIsValidCachePath/realisation1816=== CONT TestIsValidCachePath/log1817=== CONT TestIsValidCachePath/ls18182026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)1819=== CONT TestIsValidCachePath/nar_bz21820=== CONT TestIsValidCachePath/nar_xz1821=== CONT TestIsValidCachePath/nar_zst1822=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1823--- PASS: TestIsValidCachePath (0.00s)1824 --- PASS: TestIsValidCachePath/narinfo (0.00s)1825 --- PASS: TestIsValidCachePath/index.html (0.00s)1826 --- PASS: TestIsValidCachePath/short_hash (0.00s)1827 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1828 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1829 --- PASS: TestIsValidCachePath/random_path (0.00s)1830 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1831 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1832 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1833 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1834 --- PASS: TestIsValidCachePath/empty (0.00s)1835 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1836 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1837 --- PASS: TestIsValidCachePath/realisation (0.00s)1838 --- PASS: TestIsValidCachePath/log (0.00s)1839 --- PASS: TestIsValidCachePath/ls (0.00s)1840 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1841 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1842 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1843 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1844=== CONT TestParseSingleRange/none1845=== CONT TestParseSingleRange/open-ended1846=== CONT TestParseSingleRange/closed1847=== CONT TestParseSingleRange/malformed_end_before_start1848=== CONT TestParseSingleRange/malformed_both_empty1849=== CONT TestParseSingleRange/malformed_no_dash1850=== CONT TestParseSingleRange/multi-range_ignored1851=== CONT TestParseSingleRange/unknown_unit1852=== CONT TestParseSingleRange/start_past_EOF1853=== CONT TestParseSingleRange/end_clamped_to_size1854=== CONT TestParseSingleRange/single_byte1855=== CONT TestParseSingleRange/suffix_exceeds_size1856=== CONT TestParseSingleRange/suffix1857=== CONT TestParseSingleRange/start_far_past_EOF1858--- PASS: TestParseSingleRange (0.00s)1859 --- PASS: TestParseSingleRange/none (0.00s)1860 --- PASS: TestParseSingleRange/open-ended (0.00s)1861 --- PASS: TestParseSingleRange/closed (0.00s)1862 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1863 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1864 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1865 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1866 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1867 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1868 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1869 --- PASS: TestParseSingleRange/single_byte (0.00s)1870 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1871 --- PASS: TestParseSingleRange/suffix (0.00s)1872 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1873=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18742026/09/20 10:36:48 INFO Received uploads request method=POST path=/1875=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18762026/09/20 10:36:48 INFO Received complete multipart upload request method=POST path=/1877=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18782026/09/20 10:36:48 INFO Received uploads request method=POST path=/1879=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18802026/09/20 10:36:48 INFO Received request for more parts method=POST path=/1881--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1882 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1883 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1884 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1885 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1886=== CONT TestIsValidUploadKey/narinfo1887=== CONT TestIsValidUploadKey/realisation_plus_in_output1888=== CONT TestIsValidUploadKey/unknown_type1889=== CONT TestIsValidUploadKey/empty_key1890=== CONT TestIsValidUploadKey/absolute1891=== CONT TestIsValidUploadKey/traversal_nar1892=== CONT TestIsValidUploadKey/traversal1893=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1894=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1895=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1896=== CONT TestIsValidUploadKey/index.html1897=== CONT TestIsValidUploadKey/nix-cache-info1898=== CONT TestIsValidUploadKey/build_log_equals1899=== CONT TestIsValidUploadKey/realisation1900=== CONT TestIsValidUploadKey/build_log_question_mark1901=== CONT TestIsValidUploadKey/build_log_home-manager_file1902=== CONT TestIsValidUploadKey/build_log_plus_in_name1903=== CONT TestIsValidUploadKey/nar_xz1904=== CONT TestIsValidUploadKey/build_log1905=== CONT TestIsValidUploadKey/nar_plain1906=== CONT TestIsValidUploadKey/nar_zst1907=== CONT TestIsValidUploadKey/listing1908--- PASS: TestIsValidUploadKey (0.11s)1909 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1910 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1911 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1912 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1913 --- PASS: TestIsValidUploadKey/absolute (0.00s)1914 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1915 --- PASS: TestIsValidUploadKey/traversal (0.00s)1916 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1917 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1918 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1919 --- PASS: TestIsValidUploadKey/index.html (0.00s)1920 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1921 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1922 --- PASS: TestIsValidUploadKey/realisation (0.00s)1923 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1924 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1925 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1926 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1927 --- PASS: TestIsValidUploadKey/build_log (0.00s)1928 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1929 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1930 --- PASS: TestIsValidUploadKey/listing (0.00s)1931=== CONT TestProxyWriteTimeout/narinfo1932=== CONT TestProxyWriteTimeout/10_GiB_nar1933=== CONT TestProxyWriteTimeout/unknown_size1934=== CONT TestProxyWriteTimeout/1_GiB_nar1935--- PASS: TestProxyWriteTimeout (0.00s)1936 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1937 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1938 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1939 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)19402026/09/20 10:36:48 OK 20260905000000_add_claims.sql (2.99ms)1941=== CONT TestServerTLSConfig/no_client_CA1942=== CONT TestServerTLSConfig/missing_CA_file1943=== CONT TestServerTLSConfig/not_a_PEM_file1944=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19452026/09/20 10:36:48 INFO Received request for more parts method=POST path=/1946--- PASS: TestServerTLSConfig (0.00s)1947 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1948 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1949 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1950=== NAME TestNARDeduplicationMetadataUploadBug1951 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1320791383/001/store/biw6krzzhmsds89mr1m73k3bc4cnz5hi-file1.txt19522026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (5.22ms)19532026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000019542026/09/20 10:36:48 OK 1_commit_pending_closure.sql (3.39ms)19552026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.32ms)19562026/09/20 10:36:48 goose: up to current file version: 219572026-09-20 10:36:48.349 UTC [1746] ERROR: relation "goose_db_version" does not exist at character 3619582026-09-20 10:36:48.349 UTC [1746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1959--- PASS: TestReadProxyRangeRequest (0.51s)1960=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19612026/09/20 10:36:48 INFO Received complete multipart upload request method=POST path=/1962=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19632026/09/20 10:36:48 INFO Received uploads request method=POST path=/19642026/09/20 10:36:48 OK 20241026095416_initial_model.sql (14.32ms)19652026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (6.46ms)19662026/09/20 10:36:48 OK 20251218171726_add_pins.sql (4.42ms)19672026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)19682026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures19692026/09/20 10:36:48 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/present19702026/09/20 10:36:48 OK 20260905000000_add_claims.sql (2.88ms)19712026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (2.34ms)19722026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000019732026/09/20 10:36:48 OK 1_commit_pending_closure.sql (6.13ms)19742026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.74ms)19752026/09/20 10:36:48 goose: up to current file version: 219762026-09-20 10:36:48.407 UTC [1784] ERROR: relation "goose_db_version" does not exist at character 3619772026-09-20 10:36:48.407 UTC [1784] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19782026/09/20 10:36:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19792026/09/20 10:36:48 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst19802026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures1981--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.55s)1982=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1983--- PASS: TestReadProxyDisabled (0.50s)1984=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19852026/09/20 10:36:48 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]1986=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1987=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19882026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[write]19892026/09/20 10:36:48 WARN Authentication failed token_preview=eyJhbGciOi...b0mnbqPZOQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1990=== CONT TestService_RequireScope_OIDC/builder_may_write1991=== CONT TestService_RequireScope_OIDC/static_token_may_admin1992=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1993=== CONT TestService_RequireScope_OIDC/writer_implies_read19942026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[write]19952026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[write]1996=== CONT TestService_RequireScope_OIDC/static_token_may_write1997--- PASS: TestService_AuthMiddleware_OIDC (1.13s)1998 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1999 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2000 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2001 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20022026-09-20 10:36:48.418 UTC [1802] ERROR: relation "goose_db_version" does not exist at character 3620032026-09-20 10:36:48.418 UTC [1802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2004=== CONT TestService_RequireScope_OIDC/ops_may_not_write2005=== CONT TestService_RequireScope_OIDC/reader_may_read20062026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[read]2007=== CONT TestService_RequireScope_OIDC/reader_may_not_write20082026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[admin]2009=== CONT TestService_RequireScope_OIDC/ops_may_admin20102026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[read]2011=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20122026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[write]20132026/09/20 10:36:48 INFO OIDC auth successful provider=test scopes=[admin]2014--- PASS: TestService_RequireScope_OIDC (1.24s)2015 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2016 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2017 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2018 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2019 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2020 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2021 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2022 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2023 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2024 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)20252026/09/20 10:36:48 OK 20241026095416_initial_model.sql (8.03ms)20262026/09/20 10:36:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20272026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)20282026/09/20 10:36:48 OK 20251218171726_add_pins.sql (2.3ms)20292026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)20302026/09/20 10:36:48 OK 20241026095416_initial_model.sql (7.5ms)20312026/09/20 10:36:48 OK 20260905000000_add_claims.sql (2.53ms)20322026/09/20 10:36:48 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)20332026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (1.75ms)20342026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000020352026/09/20 10:36:48 OK 20251218171726_add_pins.sql (1.86ms)20362026/09/20 10:36:48 OK 1_commit_pending_closure.sql (1.67ms)20372026/09/20 10:36:48 OK 2_object_stats_trigger.sql (776.74µs)20382026/09/20 10:36:48 goose: up to current file version: 220392026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures20402026/09/20 10:36:48 OK 20260628120000_add_object_size_and_stats.sql (2.38ms)20412026/09/20 10:36:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Yzg4NzU1ZmYtODI0OC00YTcxLWJjOWMtNzc0OTAzMmQyMjc0LmIzYzc1N2E0LWRmOTYtNDQ1MC1hOTY5LTg3NTE3MjcxNzJlZngxNzg5OTAwNjA4MDE3NjAyMjMx parts=1020422026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20432026/09/20 10:36:48 OK 20260905000000_add_claims.sql (2.3ms)20442026/09/20 10:36:48 INFO Completed upload id=120452026/09/20 10:36:48 OK 20260920000000_drop_claims.sql (2.04ms)20462026/09/20 10:36:48 goose: successfully migrated database to version: 2026092000000020472026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures20482026/09/20 10:36:48 OK 1_commit_pending_closure.sql (1.38ms)20492026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures20502026/09/20 10:36:48 OK 2_object_stats_trigger.sql (1.22ms)20512026/09/20 10:36:48 goose: up to current file version: 220522026/09/20 10:36:48 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo20532026/09/20 10:36:48 WARN Found objects in DB but missing from S3, will re-upload count=12054--- PASS: TestService_verifyS3Integrity (1.15s)20552026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures20562026/09/20 10:36:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20572026/09/20 10:36:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20582026/09/20 10:36:48 INFO Uploading biw6krzzhmsds89mr1m73k3bc4cnz5hi-file1.txt (160B)20592026/09/20 10:36:48 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"20602026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures20612026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign2062=== NAME TestOrphanedObjectsGC2063 orphaned_objects_gc_test.go:290: GC Test Summary:20642026/09/20 10:36:48 WARN Failed to register uploaded object key=biw6krzzhmsds89mr1m73k3bc4cnz5hi.ls error="server returned 404: 404 page not found\n"2065 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2066 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2067 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2068 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2069 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects20702026/09/20 10:36:48 INFO Signed narinfos id=1 count=12071--- PASS: TestOrphanedObjectsGC (0.97s)20722026/09/20 10:36:48 INFO Uploading 1 narinfos20732026/09/20 10:36:48 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Yzg4NzU1ZmYtODI0OC00YTcxLWJjOWMtNzc0OTAzMmQyMjc0LjYzZDM1YjFhLWY3ODctNDI5ZC1hZmJiLTFjZDc5ZjBkMGE4ZHgxNzg5OTAwNjA4MDQxNDE1OTcz parts=1020742026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20752026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20762026/09/20 10:36:48 WARN Failed to register uploaded object key=biw6krzzhmsds89mr1m73k3bc4cnz5hi.narinfo error="server returned 404: 404 page not found\n"20772026/09/20 10:36:48 INFO Completed upload id=120782026/09/20 10:36:48 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000020792026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures20802026/09/20 10:36:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures20812026/09/20 10:36:48 INFO Completed upload id=120822026/09/20 10:36:48 INFO Upload complete. (100ms)2083=== NAME TestNARDeduplicationMetadataUploadBug2084 metadata_upload_test.go:54: Retrieved narinfo from S3:2085 StorePath: /build/TestNARDeduplicationMetadataUploadBug1320791383/001/store/biw6krzzhmsds89mr1m73k3bc4cnz5hi-file1.txt2086 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2087 Compression: zstd2088 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2089 NarSize: 1602090 References: 2091 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf20922026/09/20 10:36:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.963493ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2093 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2094 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2095 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}20962026/09/20 10:36:48 INFO Aborted multipart uploads count=02097--- PASS: TestReadRedirectKeepsNarinfoProxied (0.53s)20982026/09/20 10:36:48 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=020992026/09/20 10:36:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21002026/09/20 10:36:48 INFO Vacuumed table table=pending_closures21012026/09/20 10:36:48 INFO Vacuumed table table=pending_objects21022026/09/20 10:36:48 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yzg4NzU1ZmYtODI0OC00YTcxLWJjOWMtNzc0OTAzMmQyMjc0LjVmNDdlMGM3LTQ4MDYtNDgyYy1iNWMzLTU1NTk2NGJkMzA5N3gxNzg5OTAwNjA4NDYzNzcxMjA521032026/09/20 10:36:48 INFO Vacuumed table table=multipart_uploads21042026/09/20 10:36:48 INFO Vacuumed table table=closures21052026/09/20 10:36:48 INFO Vacuumed table table=objects21062026/09/20 10:36:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yzg4NzU1ZmYtODI0OC00YTcxLWJjOWMtNzc0OTAzMmQyMjc0LjVmNDdlMGM3LTQ4MDYtNDgyYy1iNWMzLTU1NTk2NGJkMzA5N3gxNzg5OTAwNjA4NDYzNzcxMjA5 parts=12107--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.56s)21082026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures21092026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures2110=== NAME TestNARDeduplicationMetadataUploadBug2111 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1320791383/001/store/sz5w52kyx5crgl3v2jbr2y480h7nvs0c-file2.txt2112--- PASS: TestReadRedirectNar (0.43s)21132026/09/20 10:36:48 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002114--- PASS: TestService_createPendingClosureHandler (1.24s)2115--- PASS: TestReadRedirectUsesPublicS3URL (0.45s)2116--- PASS: TestReadProxyConditionalGet (0.41s)21172026/09/20 10:36:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2118--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.42s)21192026/09/20 10:36:48 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=021202026/09/20 10:36:48 INFO Vacuumed table table=pending_closures21212026/09/20 10:36:48 INFO Vacuumed table table=pending_objects21222026/09/20 10:36:48 INFO Vacuumed table table=multipart_uploads21232026/09/20 10:36:48 INFO Vacuumed table table=closures21242026/09/20 10:36:48 INFO Vacuumed table table=objects21252026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures21262026/09/20 10:36:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)2127--- PASS: TestReadProxyHead (0.40s)21282026/09/20 10:36:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21292026/09/20 10:36:48 INFO Signed narinfos id=2 count=121302026/09/20 10:36:48 WARN Failed to register uploaded object key=sz5w52kyx5crgl3v2jbr2y480h7nvs0c.ls error="server returned 404: 404 page not found\n"21312026/09/20 10:36:48 INFO Uploading 1 narinfos21322026/09/20 10:36:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21332026/09/20 10:36:48 WARN Failed to register uploaded object key=sz5w52kyx5crgl3v2jbr2y480h7nvs0c.narinfo error="server returned 404: 404 page not found\n"21342026/09/20 10:36:48 INFO Completed upload id=221352026/09/20 10:36:48 INFO Upload complete. (84ms)2136=== NAME TestNARDeduplicationMetadataUploadBug2137 metadata_upload_test.go:76: Retrieved narinfo from S3:2138 StorePath: /build/TestNARDeduplicationMetadataUploadBug1320791383/001/store/sz5w52kyx5crgl3v2jbr2y480h7nvs0c-file2.txt2139 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2140 Compression: zstd2141 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2142 NarSize: 1602143 References: 2144 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2145 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2146 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2147 {"version":1,"root":{"type":"regular","size":44}}2148--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)21492026/09/20 10:36:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.364158ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21502026/09/20 10:36:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21512026/09/20 10:36:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21522026/09/20 10:36:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21532026/09/20 10:36:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21542026/09/20 10:36:48 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Yzg4NzU1ZmYtODI0OC00YTcxLWJjOWMtNzc0OTAzMmQyMjc0LjkxNmE2YjYzLTMyMTUtNGEzOS1iYmMxLTdlOWQzOTIxZWQxYngxNzg5OTAwNjA4NDQzMjMxNDMz parts=1221552026/09/20 10:36:48 INFO Received uploads request method=POST path=/api/pending_closures2156--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.02s)21572026/09/20 10:36:48 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=021582026/09/20 10:36:49 INFO Vacuumed table table=pending_closures21592026/09/20 10:36:49 INFO Vacuumed table table=pending_objects21602026/09/20 10:36:49 INFO Vacuumed table table=multipart_uploads21612026/09/20 10:36:49 INFO Vacuumed table table=closures21622026/09/20 10:36:49 INFO Vacuumed table table=objects21632026/09/20 10:36:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21642026/09/20 10:36:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Yzg4NzU1ZmYtODI0OC00YTcxLWJjOWMtNzc0OTAzMmQyMjc0LmUxMDkzYzhlLWNlMDktNDUzOC1hNzdiLTU0OGMwMjQ1OWIwMXgxNzg5OTAwNjA4NTI4ODQ1Njgz parts=122165--- PASS: TestRedundantMultipartUpload (0.97s)2166--- PASS: TestUploadHandlersRejectOversizedBody (0.24s)2167 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2168 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2169 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.70s)21702026/09/20 10:36:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=773.68769ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2171=== NAME TestOrphanedObjectsGCStressTest2172 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2173 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21742026/09/20 10:36:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02175=== NAME TestClientIntegration2176 client_integration_test.go:323: Objects in database after GC:2177 client_integration_test.go:323: Successfully deleted all objects with GC --force2178--- PASS: TestClientIntegration (3.14s)2179=== NAME TestOrphanedObjectsGCStressTest2180 orphaned_objects_gc_test.go:509: Stress test completed successfully:2181 orphaned_objects_gc_test.go:510: - Active objects preserved: 202182 orphaned_objects_gc_test.go:511: - Objects deleted: 2102183 orphaned_objects_gc_test.go:512: - Total GC'd: 2102184--- PASS: TestOrphanedObjectsGCStressTest (2.40s)21852026/09/20 10:36:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.570767198s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21862026/09/20 10:36:50 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02187=== NAME TestPinProtectsFromGC2188 client_integration_test.go:794: Pin successfully protected closure from garbage collection2189--- PASS: TestPinProtectsFromGC (3.44s)21902026/09/20 10:36:51 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-config21912026/09/20 10:36:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.962438ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21922026/09/20 10:36:51 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.925451ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21932026/09/20 10:36:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.554447ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21942026/09/20 10:36:52 WARN Rate limiter enabled after throttle name=s3-test rate=521952026/09/20 10:36:52 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2196=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2197 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102198 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002199--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.23s)22002026/09/20 10:36:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.737166846s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22012026/09/20 10:36:54 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"22022026/09/20 10:36:54 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_closures22032026/09/20 10:36:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.218267ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22042026/09/20 10:36:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.207491ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22052026/09/20 10:36:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.784628ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22062026/09/20 10:36:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.729387315s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2207--- PASS: TestClientErrorHandling (0.00s)2208 --- PASS: TestClientErrorHandling/InvalidStorePath (0.42s)2209 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.54s)2210 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.75s)2211PASS2212{"timestamp":"2026-09-20T10:36:58.054487045Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50516","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(394)"}22132026-09-20 10:36:58.292 UTC [129] LOG: received smart shutdown request22142026-09-20 10:36:58.295 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122152026-09-20 10:36:58.306 UTC [134] LOG: shutting down22162026-09-20 10:36:58.306 UTC [134] LOG: checkpoint starting: shutdown immediate22172026-09-20 10:36:59.662 UTC [134] LOG: checkpoint complete: wrote 11200 buffers (68.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 15 recycled; write=0.307 s, sync=1.011 s, total=1.356 s; sync files=18404, longest=0.015 s, average=0.001 s; distance=251188 kB, estimate=251188 kB; lsn=0/10CB2FD8, redo lsn=0/10CB2FD822182026-09-20 10:36:59.738 UTC [129] LOG: database system is shut down2219Running OIDC tests...2220=== RUN TestGlobMatch2221=== PAUSE TestGlobMatch2222=== RUN TestAudienceForIssuer2223=== PAUSE TestAudienceForIssuer2224=== RUN TestValidateToken_ValidToken2225=== PAUSE TestValidateToken_ValidToken2226=== RUN TestValidateToken_WrongAudience2227=== PAUSE TestValidateToken_WrongAudience2228=== RUN TestValidateToken_Expired2229=== PAUSE TestValidateToken_Expired2230=== RUN TestValidateToken_BoundClaimsMismatch2231=== PAUSE TestValidateToken_BoundClaimsMismatch2232=== RUN TestValidateToken_BoundSubjectMismatch2233=== PAUSE TestValidateToken_BoundSubjectMismatch2234=== RUN TestValidateToken_MultipleProviders2235=== PAUSE TestValidateToken_MultipleProviders2236=== RUN TestValidateToken_NoMatchingProvider2237=== PAUSE TestValidateToken_NoMatchingProvider2238=== RUN TestValidateToken_KubernetesServiceAccount2239=== PAUSE TestValidateToken_KubernetesServiceAccount2240=== RUN TestNewValidator_KubernetesRequiresCA2241=== PAUSE TestNewValidator_KubernetesRequiresCA2242=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2243=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2244=== RUN TestScopes_LegacyProviderDefaultsToWrite2245=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2246=== RUN TestScopes_Rules2247=== PAUSE TestScopes_Rules2248=== RUN TestScopes_ConfigValidation2249=== PAUSE TestScopes_ConfigValidation2250=== CONT TestGlobMatch2251=== CONT TestValidateToken_BoundClaimsMismatch2252=== CONT TestValidateToken_Expired2253=== CONT TestValidateToken_MultipleProviders2254=== CONT TestValidateToken_BoundSubjectMismatch2255=== RUN TestGlobMatch/foo_foo2256=== PAUSE TestGlobMatch/foo_foo2257=== RUN TestGlobMatch/foo_bar2258=== PAUSE TestGlobMatch/foo_bar2259=== RUN TestGlobMatch/*_2260=== PAUSE TestGlobMatch/*_2261=== RUN TestGlobMatch/*_anything2262=== PAUSE TestGlobMatch/*_anything2263=== CONT TestAudienceForIssuer2264=== CONT TestValidateToken_WrongAudience2265=== CONT TestScopes_LegacyProviderDefaultsToWrite2266=== CONT TestScopes_ConfigValidation2267=== CONT TestScopes_Rules2268=== CONT TestNewValidator_KubernetesRequiresCA2269=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2270=== CONT TestValidateToken_KubernetesServiceAccount2271=== CONT TestValidateToken_NoMatchingProvider2272=== CONT TestValidateToken_ValidToken2273=== RUN TestGlobMatch/foo*_foo2274=== PAUSE TestGlobMatch/foo*_foo2275=== RUN TestGlobMatch/foo*_foobar2276=== PAUSE TestGlobMatch/foo*_foobar2277=== RUN TestGlobMatch/foo*_bar2278=== PAUSE TestGlobMatch/foo*_bar2279=== RUN TestGlobMatch/*bar_bar2280=== PAUSE TestGlobMatch/*bar_bar2281=== RUN TestGlobMatch/*bar_foobar2282=== PAUSE TestGlobMatch/*bar_foobar2283=== RUN TestGlobMatch/*bar_foo2284=== PAUSE TestGlobMatch/*bar_foo2285=== RUN TestGlobMatch/foo*bar_foobar2286=== PAUSE TestGlobMatch/foo*bar_foobar2287=== RUN TestGlobMatch/foo*bar_foo123bar2288=== PAUSE TestGlobMatch/foo*bar_foo123bar2289=== RUN TestGlobMatch/foo*bar_foobarbaz2290=== PAUSE TestGlobMatch/foo*bar_foobarbaz2291=== RUN TestGlobMatch/*/*_foo/bar2292=== PAUSE TestGlobMatch/*/*_foo/bar2293--- PASS: TestAudienceForIssuer (0.00s)2294=== RUN TestGlobMatch/*/*_foo2295=== 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?_fo2306=== RUN TestGlobMatch/fo?_fooo2307=== PAUSE TestGlobMatch/fo?_fooo2308=== RUN TestGlobMatch/?oo_foo2309=== PAUSE TestGlobMatch/?oo_foo2310=== RUN TestGlobMatch/?oo_boo2311=== PAUSE TestGlobMatch/?oo_boo2312=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2313=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2314=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main23152026/09/20 10:37:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42771/oidc23162026/09/20 10:37:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46549/oidc23172026/09/20 10:37:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43223/oidc2318--- PASS: TestScopes_ConfigValidation (0.01s)23192026/09/20 10:37:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32913/oidc23202026/09/20 10:37:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42721/oidc2321=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main23222026/09/20 10:37:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35399/oidc2323=== CONT TestGlobMatch/foo_foo23242026/09/20 10:37:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33963/oidc23252026/09/20 10:37:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43281/oidc2326=== CONT TestGlobMatch/*/*_foo/bar2327=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main23282026/09/20 10:37:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35977/oidc2329=== CONT TestGlobMatch/fo?_foo2330=== CONT TestGlobMatch/*bar_bar2331=== CONT TestGlobMatch/foo*bar_foobar2332=== CONT TestGlobMatch/foo*_foo2333=== CONT TestGlobMatch/*bar_foo2334=== CONT TestGlobMatch/*bar_foobar2335=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main23362026/09/20 10:37:01 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232337=== CONT TestGlobMatch/?oo_boo2338=== CONT TestGlobMatch/?oo_foo2339=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.023402026/09/20 10:37:01 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46653/oidc2341=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2342=== CONT TestGlobMatch/refs/*/main_refs/heads/main2343=== CONT TestGlobMatch/fo?_fooo2344=== CONT TestGlobMatch/fo?_fo2345=== CONT TestGlobMatch/*/*_foo2346=== CONT TestGlobMatch/foo*_bar2347=== CONT TestGlobMatch/foo*bar_foobarbaz2348=== CONT TestGlobMatch/foo*_foobar2349=== CONT TestGlobMatch/foo*bar_foo123bar2350=== CONT TestGlobMatch/*_2351=== CONT TestGlobMatch/*_anything2352=== CONT TestGlobMatch/foo_bar2353--- PASS: TestGlobMatch (0.01s)2354 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2355 --- PASS: TestGlobMatch/fo?_foo (0.00s)2356 --- PASS: TestGlobMatch/*bar_bar (0.00s)2357 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2358 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2359 --- PASS: TestGlobMatch/foo*_foo (0.00s)2360 --- PASS: TestGlobMatch/foo_foo (0.00s)2361 --- PASS: TestGlobMatch/*bar_foo (0.00s)2362 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2363 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2364 --- PASS: TestGlobMatch/?oo_boo (0.00s)2365 --- PASS: TestGlobMatch/?oo_foo (0.00s)2366 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2367 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2368 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2369 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2370 --- PASS: TestGlobMatch/fo?_fo (0.00s)2371 --- PASS: TestGlobMatch/*/*_foo (0.00s)2372 --- PASS: TestGlobMatch/foo*_bar (0.00s)2373 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2374 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2375 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2376 --- PASS: TestGlobMatch/*_ (0.00s)2377 --- PASS: TestGlobMatch/*_anything (0.00s)2378 --- PASS: TestGlobMatch/foo_bar (0.00s)2379--- PASS: TestValidateToken_Expired (0.02s)2380--- PASS: TestValidateToken_ValidToken (0.02s)2381--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2382--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2383--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2384--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2385--- PASS: TestValidateToken_WrongAudience (0.02s)23862026/09/20 10:37:01 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:447212387--- PASS: TestValidateToken_MultipleProviders (0.02s)2388--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2389--- PASS: TestScopes_Rules (0.02s)2390--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)23912026/09/20 10:37:01 http: TLS handshake error from 127.0.0.1:41680: remote error: tls: bad certificate2392--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2393PASS2394Running hook tests...2395=== RUN TestSendPathsEmpty2396=== PAUSE TestSendPathsEmpty2397=== RUN TestQueueEnqueueAndFetch2398=== PAUSE TestQueueEnqueueAndFetch2399=== RUN TestQueueDeduplication2400=== PAUSE TestQueueDeduplication2401=== RUN TestQueueRemove2402=== PAUSE TestQueueRemove2403=== RUN TestQueueFetchBatchLimit2404=== PAUSE TestQueueFetchBatchLimit2405=== RUN TestQueueRetryMovesToBack2406=== PAUSE TestQueueRetryMovesToBack2407=== RUN TestQueueFetchRemoveLifecycle2408=== PAUSE TestQueueFetchRemoveLifecycle2409=== RUN TestQueueConcurrentWriters2410=== PAUSE TestQueueConcurrentWriters2411=== RUN TestQueueRemoveLargeClosure2412=== PAUSE TestQueueRemoveLargeClosure2413=== RUN TestServerClientIntegration2414=== PAUSE TestServerClientIntegration2415=== RUN TestServerQueueError2416=== PAUSE TestServerQueueError2417=== RUN TestGetListenerSocketActivation2418 server_test.go:210: === RUN TestGetListenerSocketActivation2419 --- PASS: TestGetListenerSocketActivation (0.00s)2420 PASS2421 2422--- PASS: TestGetListenerSocketActivation (0.01s)2423=== RUN TestDrainIsolatesPoisonPath2424=== PAUSE TestDrainIsolatesPoisonPath2425=== RUN TestRunNotBlockedByPoisonHead2426=== PAUSE TestRunNotBlockedByPoisonHead2427=== RUN TestDrainGivesUpWhenServerDown2428=== PAUSE TestDrainGivesUpWhenServerDown2429=== RUN TestFailedPathPrunedByLaterClosure2430=== PAUSE TestFailedPathPrunedByLaterClosure2431=== RUN TestWorkerUploadsAndRemoves2432=== PAUSE TestWorkerUploadsAndRemoves2433=== RUN TestWorkerSkipsGCdPaths2434=== PAUSE TestWorkerSkipsGCdPaths2435=== RUN TestWorkerPrunesClosureDeps2436=== PAUSE TestWorkerPrunesClosureDeps2437=== RUN TestDrainTimeout2438=== PAUSE TestDrainTimeout2439=== CONT TestSendPathsEmpty2440=== CONT TestServerQueueError2441--- PASS: TestSendPathsEmpty (0.00s)2442=== CONT TestServerClientIntegration2443=== CONT TestQueueRemoveLargeClosure2444=== CONT TestQueueConcurrentWriters2445=== CONT TestQueueFetchRemoveLifecycle2446=== CONT TestQueueRetryMovesToBack2447=== CONT TestQueueFetchBatchLimit2448=== CONT TestQueueRemove2449=== CONT TestQueueDeduplication24502026/09/20 10:37:01 ERROR Failed to queue paths error="permission denied" count=12451=== CONT TestQueueEnqueueAndFetch2452--- PASS: TestServerClientIntegration (0.00s)2453=== CONT TestDrainGivesUpWhenServerDown2454=== CONT TestFailedPathPrunedByLaterClosure2455=== CONT TestWorkerPrunesClosureDeps2456=== CONT TestDrainTimeout2457=== CONT TestWorkerUploadsAndRemoves2458=== CONT TestWorkerSkipsGCdPaths2459=== CONT TestRunNotBlockedByPoisonHead2460=== CONT TestDrainIsolatesPoisonPath2461--- PASS: TestServerQueueError (0.00s)24622026/09/20 10:37:01 INFO Upload queue status pending=324632026/09/20 10:37:01 INFO Uploading batch count=224642026/09/20 10:37:01 INFO Upload queue status pending=224652026/09/20 10:37:01 INFO Uploading batch count=124662026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=124672026/09/20 10:37:01 INFO Uploading batch count=124682026/09/20 10:37:01 INFO Uploading batch count=124692026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=124702026/09/20 10:37:01 INFO Uploading batch count=424712026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=424722026/09/20 10:37:01 INFO Upload queue status pending=224732026/09/20 10:37:01 INFO Uploading batch count=224742026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=224752026/09/20 10:37:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3423738835/002/a24762026/09/20 10:37:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath190734090/002/bbb2477--- PASS: TestQueueDeduplication (0.02s)24782026/09/20 10:37:01 INFO Uploading batch count=224792026/09/20 10:37:01 INFO Uploading batch count=12480--- PASS: TestQueueRetryMovesToBack (0.02s)2481--- PASS: TestQueueFetchBatchLimit (0.02s)2482--- PASS: TestQueueEnqueueAndFetch (0.02s)24832026/09/20 10:37:01 INFO Uploading batch count=124842026/09/20 10:37:01 INFO Upload queue status pending=224852026/09/20 10:37:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3423738835/002/b2486--- PASS: TestQueueFetchRemoveLifecycle (0.03s)24872026/09/20 10:37:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3439090150/002/nonexistent2488--- PASS: TestQueueRemove (0.03s)24892026/09/20 10:37:01 INFO Uploading batch count=124902026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=124912026/09/20 10:37:01 INFO Uploading batch count=224922026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=224932026/09/20 10:37:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3423738835/002/c24942026/09/20 10:37:01 INFO Uploading batch count=124952026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=124962026/09/20 10:37:01 INFO Uploading batch count=124972026/09/20 10:37:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3423738835/002/d24982026/09/20 10:37:01 INFO Uploading batch count=12499--- PASS: TestWorkerUploadsAndRemoves (0.03s)25002026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=125012026/09/20 10:37:01 INFO Uploading batch count=225022026/09/20 10:37:01 ERROR Upload failed error="upload failed" count=225032026/09/20 10:37:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3423738835/002/e25042026/09/20 10:37:01 ERROR Drain finished with paths left in queue remaining=125052026/09/20 10:37:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3423738835/002/f2506--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)25072026/09/20 10:37:01 ERROR Drain finished with paths left in queue remaining=102508--- PASS: TestDrainIsolatesPoisonPath (0.03s)2509--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2510--- PASS: TestWorkerPrunesClosureDeps (0.04s)2511--- PASS: TestWorkerSkipsGCdPaths (0.04s)2512--- PASS: TestQueueRemoveLargeClosure (0.11s)25132026/09/20 10:37:01 ERROR Upload failed error="context deadline exceeded" count=225142026/09/20 10:37:01 ERROR Drain finished with paths left in queue remaining=42515--- PASS: TestDrainTimeout (0.22s)2516--- PASS: TestQueueConcurrentWriters (0.39s)25172026/09/20 10:37:02 INFO Uploading batch count=125182026/09/20 10:37:02 INFO Uploading batch count=125192026/09/20 10:37:02 INFO Uploading batch count=125202026/09/20 10:37:02 ERROR Upload failed error="upload failed" count=125212026/09/20 10:37:02 INFO Uploading batch count=125222026/09/20 10:37:02 ERROR Upload failed error="upload failed" count=125232026/09/20 10:37:02 INFO Uploading batch count=125242026/09/20 10:37:02 ERROR Upload failed error="upload failed" count=125252026/09/20 10:37:02 INFO Uploading batch count=125262026/09/20 10:37:02 ERROR Upload failed error="upload failed" count=125272026/09/20 10:37:02 ERROR Drain finished with paths left in queue remaining=12528--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2529PASS

succeeded niks3-go-unit-tests checks.x86_64-linux.go-unit-tests · build #226 · raw

succeeded `niks3-go-unit-tests` `checks.x86_64-linux.go-unit-tests` · build #226 · raw