niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #229
· 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.03s)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 TestConvertHashToNix3291=== RUN TestConvertHashToNix32/SRI_format_to_Nix3292=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3293=== RUN TestConvertHashToNix32/already_Nix32_format94=== PAUSE TestConvertHashToNix32/already_Nix32_format95=== RUN TestConvertHashToNix32/invalid_format96=== PAUSE TestConvertHashToNix32/invalid_format97=== CONT TestShellSplit98=== CONT TestScriptTokenEmptyCommand99--- PASS: TestScriptTokenEmptyCommand (0.00s)100=== CONT TestResolveStorePath101=== CONT TestScriptTokenScriptFails102--- PASS: TestShellSplit (0.00s)103=== CONT TestDumpPathSingleFile104=== CONT TestScriptTokenBadJSON105=== CONT TestScriptTokenEmptyToken106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestScriptTokenNoExpiryRerunsEveryCall108=== CONT TestFileTokenEmpty109=== CONT TestFileTokenMissing110=== CONT TestFileTokenReadsAndCaches111=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess112=== CONT TestStaticToken113=== CONT TestSetClientTLSErrors114=== CONT TestSetClientTLSDoesNotMutateDefaultTransport115=== CONT TestSetClientTLS116=== CONT TestStreamPushBatchesUnderLoad117=== CONT TestStreamPushReportsEveryPath118=== CONT TestDumpPathMatchesNix119=== CONT TestShellSplitErrors120=== CONT TestEncodeNixBase32WithRealHash121=== CONT TestEncodeNixBase32122=== CONT TestPathInfoCACompatibility123=== CONT TestDumpPathWriterError124=== CONT TestDoWithRetry_BodyReplayedViaGetBody125--- PASS: TestResolveStorePath (0.00s)126=== CONT TestRateLimiterFeedback127=== CONT TestUploadMultipart_SupersededByPeer128=== CONT TestPartSizeForNAR129=== CONT TestParsePathInfoJSONMultiplePaths130=== RUN TestEncodeNixBase32/test_string_hash131=== RUN TestUploadMultipart_SupersededByPeer/exists132=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths133=== CONT TestFilterOversizedClosures1342026/09/20 16:24:12 WARN Rate limiter enabled after throttle name=server-test rate=5135=== RUN TestFilterOversizedClosures/no_limit_keeps_everything136=== CONT TestCaseHackSuffix137=== RUN TestRateLimiterFeedback/429_enables_limiter138=== RUN TestPathInfoCACompatibility/null_ca_field139=== RUN TestPartSizeForNAR/zero_stays_at_minimum140--- PASS: TestScriptTokenScriptFails (0.00s)141--- PASS: TestFileTokenMissing (0.00s)142--- PASS: TestFileTokenEmpty (0.00s)143--- PASS: TestStaticToken (0.00s)144--- PASS: TestShellSplitErrors (0.00s)145--- PASS: TestEncodeNixBase32WithRealHash (0.00s)146=== PAUSE TestEncodeNixBase32/test_string_hash147=== PAUSE TestUploadMultipart_SupersededByPeer/exists148=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== CONT TestParsePathInfoJSON151--- PASS: TestFileTokenReadsAndCaches (0.00s)152=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything153--- PASS: TestStreamPushReportsEveryPath (0.00s)154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== RUN TestEncodeNixBase32/empty_input156=== PAUSE TestEncodeNixBase32/empty_input157=== CONT TestPathInfoHashCompatibility158--- PASS: TestScriptTokenEmptyToken (0.00s)159=== CONT TestRegisterUploadedObjectReusesConnections160=== CONT TestStreamPushRequestLine161=== RUN TestParsePathInfoJSON/Nix_format1622026/09/20 16:24:12 WARN Rate limiter enabled after throttle name=server-test rate=51632026/09/20 16:24:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40295164=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped1652026/09/20 16:24:12 ERROR Upload failed error=boom count=1166=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped167=== RUN TestFilterOversizedClosures/all_closures_skipped168=== PAUSE TestParsePathInfoJSON/Nix_format169=== CONT TestGetStorePathHash170=== PAUSE TestRateLimiterFeedback/429_enables_limiter171=== PAUSE TestPathInfoCACompatibility/null_ca_field172=== CONT TestStreamPushGivesUpOnDeadServer173=== RUN TestRateLimiterFeedback/503_enables_limiter174=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175--- PASS: TestScriptTokenBadJSON (0.01s)176--- PASS: TestDoServerRequestAttachesToken (0.01s)177=== RUN TestSetClientTLSErrors/missing_cert_file178=== RUN TestUploadMultipart_SupersededByPeer/missing179=== PAUSE TestFilterOversizedClosures/all_closures_skipped180=== CONT TestStreamPushIsolatesFailures181=== RUN TestParsePathInfoJSON/Lix_format1822026/09/20 16:24:12 ERROR Upload failed error="connection refused" count=20183=== RUN TestGetStorePathHash/valid_store_path1842026/09/20 16:24:12 ERROR Server seems unavailable, giving up on batch untried=17185=== RUN TestPathInfoCACompatibility/old_string_format_-_text186=== PAUSE TestGetStorePathHash/valid_store_path187=== RUN TestGetStorePathHash/basename_without_hyphen_should_error188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text189=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error1902026/09/20 16:24:12 ERROR Upload failed error="bad path" count=3191--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)192=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive193=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive194--- PASS: TestStreamPushIsolatesFailures (0.00s)195=== CONT TestConvertHashToNix32/invalid_format196=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths197=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error198=== PAUSE TestRateLimiterFeedback/503_enables_limiter199=== RUN TestPathInfoCACompatibility/new_structured_format_-_text200=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths201=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum202=== CONT TestConvertHashToNix32/SRI_format_to_Nix32203=== CONT TestConvertHashToNix32/already_Nix32_format204=== PAUSE TestSetClientTLSErrors/missing_cert_file205=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text206=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error207=== CONT TestEncodeNixBase32/empty_input208=== CONT TestFilterOversizedClosures/no_limit_keeps_everything209=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== CONT TestFilterOversizedClosures/all_closures_skipped2112026/09/20 16:24:12 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=50212=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)213=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter214=== RUN TestSetClientTLSErrors/missing_key_file215=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon216=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon217=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2182026/09/20 16:24:12 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=2000219=== PAUSE TestUploadMultipart_SupersededByPeer/missing220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2222026/09/20 16:24:12 WARN Rate limiter backed off name=server-test rate=52232026/09/20 16:24:12 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40295224--- PASS: TestConvertHashToNix32 (0.00s)225 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)226 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)227 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)228=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error229=== PAUSE TestParsePathInfoJSON/Lix_format230=== CONT TestEncodeNixBase32/test_string_hash231=== RUN TestSetClientTLS/rejects_connection_without_client_cert232=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI233--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)234 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)235 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.01s)236=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512237=== PAUSE TestSetClientTLSErrors/missing_key_file238=== PAUSE TestPartSizeForNAR/small_stays_at_minimum239=== CONT TestUploadMultipart_SupersededByPeer/missing240=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter241=== RUN TestParsePathInfoJSON/empty_input242=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method243=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512244=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive245=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)246--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)247--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)248--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)249=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum250=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum251=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error252=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter253=== PAUSE TestParsePathInfoJSON/empty_input254=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert255=== RUN TestSetClientTLSErrors/missing_ca_file256=== CONT TestPathInfoCACompatibility/old_string_format_-_text257=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA258=== CONT TestGetStorePathHash/basename_without_hyphen_should_error259=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method260=== PAUSE TestSetClientTLSErrors/missing_ca_file261=== CONT TestPathInfoCACompatibility/null_ca_field262=== CONT TestUploadMultipart_SupersededByPeer/exists263=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512264=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI265=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon266--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)267=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts268=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts269=== CONT TestGetStorePathHash/valid_store_path270=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error271=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error272=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter273=== RUN TestParsePathInfoJSON/whitespace_only274=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter275=== CONT TestRateLimiterFeedback/429_enables_limiter276=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA277=== RUN TestSetClientTLSErrors/invalid_ca_file278=== PAUSE TestSetClientTLSErrors/invalid_ca_file279=== CONT TestSetClientTLSErrors/missing_cert_file280=== CONT TestSetClientTLSErrors/invalid_ca_file281--- PASS: TestDumpPathSingleFile (0.03s)282=== RUN TestPartSizeForNAR/1_TiB283=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter284=== CONT TestPathInfoCACompatibility/new_structured_format_-_text285=== CONT TestRateLimiterFeedback/503_enables_limiter286=== PAUSE TestParsePathInfoJSON/whitespace_only287=== RUN TestParsePathInfoJSON/invalid_JSON288=== PAUSE TestParsePathInfoJSON/invalid_JSON289=== CONT TestParsePathInfoJSON/Nix_format290=== CONT TestParsePathInfoJSON/whitespace_only291=== CONT TestParsePathInfoJSON/invalid_JSON292=== RUN TestSetClientTLS/preserves_debug_logging_transport293=== PAUSE TestSetClientTLS/preserves_debug_logging_transport294=== CONT TestSetClientTLS/rejects_connection_without_client_cert295=== CONT TestSetClientTLS/preserves_debug_logging_transport296=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA297=== CONT TestParsePathInfoJSON/empty_input298=== CONT TestSetClientTLSErrors/missing_ca_file2992026/09/20 16:24:12 WARN Rate limiter enabled after throttle name=server-test rate=53002026/09/20 16:24:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:45151301=== CONT TestSetClientTLSErrors/missing_key_file302=== PAUSE TestPartSizeForNAR/1_TiB303=== RUN TestPartSizeForNAR/5_TiB_S3_max_object304=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object305=== RUN TestPartSizeForNAR/capped_at_5_GiB306=== PAUSE TestPartSizeForNAR/capped_at_5_GiB307=== CONT TestPartSizeForNAR/zero_stays_at_minimum308--- PASS: TestFilterOversizedClosures (0.01s)309 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)310 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)311 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3122026/09/20 16:24:12 WARN Rate limiter backed off name=server-test rate=5313=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts314=== CONT TestPartSizeForNAR/1_TiB315=== CONT TestPartSizeForNAR/small_stays_at_minimum316=== CONT TestParsePathInfoJSON/Lix_format317=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum318--- PASS: TestPathInfoHashCompatibility (0.03s)319 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)320 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)321 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)322 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)323--- PASS: TestEncodeNixBase32 (0.00s)324 --- PASS: TestEncodeNixBase32/empty_input (0.00s)325 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)326=== CONT TestPartSizeForNAR/5_TiB_S3_max_object327=== CONT TestPartSizeForNAR/capped_at_5_GiB328--- PASS: TestCaseHackSuffix (0.04s)3292026/09/20 16:24:12 WARN Rate limiter enabled after throttle name=server-test rate=5330--- PASS: TestParsePathInfoJSON (0.04s)331 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)332 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)333 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)334 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)335 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3362026/09/20 16:24:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:45911337--- PASS: TestPathInfoCACompatibility (0.03s)338 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)339 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)342 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)343--- PASS: TestGetStorePathHash (0.03s)344 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)345 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)347 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)348--- PASS: TestPartSizeForNAR (0.04s)349 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)350 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)351 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)352 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)353 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)354 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)355 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)3562026/09/20 16:24:12 WARN Rate limiter backed off name=server-test rate=5357--- PASS: TestSetClientTLSErrors (0.04s)358 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)359 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)360 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)361 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)362--- PASS: TestRateLimiterFeedback (0.04s)363 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)364 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)365 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)366 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)367--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)368 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)369 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)3702026/09/20 16:24:12 http: TLS handshake error from 127.0.0.1:43298: remote error: tls: bad certificate371--- PASS: TestSetClientTLS (0.04s)372 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)373 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)374 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)375--- PASS: TestStreamPushRequestLine (0.05s)376--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)377--- PASS: TestDumpPathWriterError (0.07s)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/postgres3892293201/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/postgres3892293201/data -l logfile start409410/build/postgres3892293201:5432 - no response4112026-09-20 16:24:14.320 UTC [131] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4122026-09-20 16:24:14.321 UTC [131] LOG: listening on Unix socket "/build/postgres3892293201/.s.PGSQL.5432"4132026-09-20 16:24:14.326 UTC [138] LOG: database system was shut down at 2026-09-20 16:24:14 UTC4142026-09-20 16:24:14.330 UTC [131] LOG: database system is ready to accept connections415/build/postgres3892293201: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 16:24:14.701 UTC [567] ERROR: relation "goose_db_version" does not exist at character 364562026-09-20 16:24:14.701 UTC [567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4572026/09/20 16:24:14 OK 20241026095416_initial_model.sql (7.28ms)4582026/09/20 16:24:14 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)4592026/09/20 16:24:14 OK 20251218171726_add_pins.sql (1.9ms)4602026/09/20 16:24:14 OK 20260628120000_add_object_size_and_stats.sql (1.87ms)4612026/09/20 16:24:14 OK 20260905000000_add_claims.sql (2.46ms)4622026/09/20 16:24:14 OK 20260920000000_drop_claims.sql (1.38ms)4632026/09/20 16:24:14 goose: successfully migrated database to version: 202609200000004642026/09/20 16:24:14 OK 1_commit_pending_closure.sql (1.24ms)4652026/09/20 16:24:14 OK 2_object_stats_trigger.sql (662.93µs)4662026/09/20 16:24:14 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 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5682026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5692026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5702026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/20 16:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/20 16:24:14 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 TestReadProxy404600=== CONT TestService_Rustfstest601=== CONT TestPresignedUploadRegisteredBeforeCommit602=== CONT TestUploadHandlersRejectOversizedBody603=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT604=== CONT TestCompleteMultipartUnregistered605=== CONT TestService_verifyS3Integrity606=== CONT TestService_createPendingClosureHandler607=== CONT TestService_cleanupPendingClosuresHandler608=== CONT TestProxyWriteTimeout609=== CONT TestUploadHandlersRejectInvalidKeys610=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info611=== CONT TestIsValidUploadKey612=== RUN TestIsValidUploadKey/narinfo613=== CONT TestSkippedUploadsHandler614=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle615=== CONT TestReadProxyRootRedirectsToIndexHTML616=== CONT TestReadRedirectNar617=== CONT TestReadProxyDisabled6182026/09/20 16:24:14 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000619=== CONT TestReadProxyInvalidPath620=== CONT TestGCTaskStore_GetReturnsLatest621=== CONT TestReadProxyNarStreaming622=== CONT TestReadProxyNarinfoAlreadyDecompressed623=== CONT TestReadProxyHead624=== CONT TestReadRedirectKeepsNarinfoProxied625=== RUN TestProxyWriteTimeout/narinfo626=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info627=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal628=== PAUSE TestIsValidUploadKey/narinfo629--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)630=== CONT TestIsValidCachePath631=== CONT TestReadProxyNarinfo632--- PASS: TestSkippedUploadsHandler (0.01s)633=== RUN TestIsValidUploadKey/nar_zst634=== RUN TestIsValidCachePath/narinfo635=== PAUSE TestIsValidUploadKey/nar_zst636=== PAUSE TestIsValidCachePath/narinfo637=== RUN TestIsValidUploadKey/nar_xz638=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars639=== PAUSE TestProxyWriteTimeout/narinfo640=== RUN TestProxyWriteTimeout/1_GiB_nar641=== PAUSE TestIsValidUploadKey/nar_xz642=== RUN TestIsValidUploadKey/nar_plain643=== PAUSE TestIsValidUploadKey/nar_plain644=== RUN TestIsValidUploadKey/listing645=== PAUSE TestIsValidUploadKey/listing646=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars647=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal648=== PAUSE TestProxyWriteTimeout/1_GiB_nar649=== RUN TestIsValidUploadKey/build_log650=== PAUSE TestIsValidUploadKey/build_log651=== RUN TestIsValidCachePath/nar_zst652=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key653=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key654=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key655=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key656=== RUN TestProxyWriteTimeout/10_GiB_nar657=== PAUSE TestProxyWriteTimeout/10_GiB_nar658=== RUN TestProxyWriteTimeout/unknown_size659=== PAUSE TestProxyWriteTimeout/unknown_size660=== CONT TestResurrectedObjectNotDeleted661=== RUN TestIsValidUploadKey/build_log_home-manager_file662=== PAUSE TestIsValidUploadKey/build_log_home-manager_file663=== RUN TestIsValidUploadKey/build_log_plus_in_name664=== PAUSE TestIsValidCachePath/nar_zst665=== CONT TestParseSingleRange666=== RUN TestParseSingleRange/none667=== PAUSE TestParseSingleRange/none668=== PAUSE TestIsValidUploadKey/build_log_plus_in_name669=== RUN TestIsValidUploadKey/build_log_question_mark670=== PAUSE TestIsValidUploadKey/build_log_question_mark671=== RUN TestIsValidUploadKey/build_log_equals672=== PAUSE TestIsValidUploadKey/build_log_equals673=== RUN TestIsValidUploadKey/realisation674=== PAUSE TestIsValidUploadKey/realisation675=== RUN TestIsValidUploadKey/realisation_plus_in_output676=== PAUSE TestIsValidUploadKey/realisation_plus_in_output677=== RUN TestIsValidUploadKey/nix-cache-info678=== PAUSE TestIsValidUploadKey/nix-cache-info679=== RUN TestIsValidUploadKey/index.html680=== PAUSE TestIsValidUploadKey/index.html681=== RUN TestIsValidUploadKey/narinfo_key,_nar_type682=== RUN TestIsValidCachePath/nar_xz683=== RUN TestParseSingleRange/unknown_unit684=== PAUSE TestParseSingleRange/unknown_unit685=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type686=== PAUSE TestIsValidCachePath/nar_xz687=== RUN TestIsValidCachePath/nar_bz2688=== PAUSE TestIsValidCachePath/nar_bz2689=== RUN TestIsValidCachePath/nar_uncompressed690=== RUN TestParseSingleRange/multi-range_ignored691=== PAUSE TestParseSingleRange/multi-range_ignored692=== RUN TestIsValidUploadKey/nar_key,_narinfo_type693=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type694=== RUN TestIsValidUploadKey/listing_key,_narinfo_type695=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type696=== RUN TestIsValidUploadKey/traversal697=== PAUSE TestIsValidCachePath/nar_uncompressed698=== RUN TestParseSingleRange/malformed_no_dash699=== PAUSE TestParseSingleRange/malformed_no_dash700=== RUN TestParseSingleRange/malformed_both_empty701=== PAUSE TestParseSingleRange/malformed_both_empty702=== PAUSE TestIsValidUploadKey/traversal703=== RUN TestIsValidCachePath/ls704=== PAUSE TestIsValidCachePath/ls705=== RUN TestIsValidCachePath/log706=== PAUSE TestIsValidCachePath/log707=== RUN TestIsValidCachePath/realisation708=== PAUSE TestIsValidCachePath/realisation709=== RUN TestIsValidCachePath/nix-cache-info710=== PAUSE TestIsValidCachePath/nix-cache-info711=== RUN TestIsValidCachePath/index.html712=== RUN TestParseSingleRange/malformed_end_before_start713=== PAUSE TestParseSingleRange/malformed_end_before_start714=== RUN TestIsValidUploadKey/traversal_nar715=== PAUSE TestIsValidUploadKey/traversal_nar716=== PAUSE TestIsValidCachePath/index.html717=== RUN TestIsValidCachePath/traversal_parent718=== PAUSE TestIsValidCachePath/traversal_parent719=== RUN TestIsValidCachePath/traversal_in_middle720=== PAUSE TestIsValidCachePath/traversal_in_middle721=== RUN TestIsValidCachePath/invalid_char_e722=== PAUSE TestIsValidCachePath/invalid_char_e723=== RUN TestIsValidCachePath/invalid_char_u724=== PAUSE TestIsValidCachePath/invalid_char_u725=== RUN TestIsValidCachePath/random_path726=== PAUSE TestIsValidCachePath/random_path727=== RUN TestIsValidCachePath/empty728=== RUN TestParseSingleRange/closed729=== PAUSE TestParseSingleRange/closed730=== RUN TestParseSingleRange/open-ended731=== PAUSE TestParseSingleRange/open-ended732=== RUN TestParseSingleRange/end_clamped_to_size733=== PAUSE TestParseSingleRange/end_clamped_to_size734=== RUN TestParseSingleRange/suffix735=== RUN TestIsValidUploadKey/absolute736=== PAUSE TestIsValidCachePath/empty737=== RUN TestIsValidCachePath/leading_slash738=== PAUSE TestIsValidCachePath/leading_slash739=== PAUSE TestParseSingleRange/suffix740=== PAUSE TestIsValidUploadKey/absolute741=== RUN TestIsValidUploadKey/empty_key742=== PAUSE TestIsValidUploadKey/empty_key743=== RUN TestIsValidUploadKey/unknown_type744=== PAUSE TestIsValidUploadKey/unknown_type745=== RUN TestIsValidCachePath/wrong_extension746=== PAUSE TestIsValidCachePath/wrong_extension747=== RUN TestParseSingleRange/suffix_exceeds_size748=== PAUSE TestParseSingleRange/suffix_exceeds_size749=== CONT TestOrphanedObjectsGCStressTest750=== RUN TestIsValidCachePath/short_hash751=== PAUSE TestIsValidCachePath/short_hash752=== RUN TestParseSingleRange/single_byte753=== PAUSE TestParseSingleRange/single_byte754=== RUN TestParseSingleRange/start_past_EOF755=== PAUSE TestParseSingleRange/start_past_EOF756=== RUN TestParseSingleRange/start_far_past_EOF757=== PAUSE TestParseSingleRange/start_far_past_EOF758=== CONT TestOrphanedObjectsGC7592026-09-20 16:24:15.210 UTC [623] ERROR: relation "goose_db_version" does not exist at character 367602026-09-20 16:24:15.210 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7612026-09-20 16:24:15.210 UTC [625] ERROR: relation "goose_db_version" does not exist at character 367622026-09-20 16:24:15.210 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC763=== CONT TestObjectStatsTrigger7642026-09-20 16:24:15.210 UTC [624] ERROR: relation "goose_db_version" does not exist at character 367652026-09-20 16:24:15.210 UTC [624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7662026-09-20 16:24:15.210 UTC [626] ERROR: relation "goose_db_version" does not exist at character 367672026-09-20 16:24:15.210 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC768=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts769=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts770=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure771=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure772=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart773=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart774=== CONT TestMultipartCleanup7752026-09-20 16:24:15.325 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367762026-09-20 16:24:15.325 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-09-20 16:24:15.326 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367782026-09-20 16:24:15.326 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026-09-20 16:24:15.326 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367802026-09-20 16:24:15.326 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026-09-20 16:24:15.352 UTC [648] ERROR: relation "goose_db_version" does not exist at character 367822026-09-20 16:24:15.352 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026-09-20 16:24:15.363 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367842026-09-20 16:24:15.363 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7852026/09/20 16:24:15 OK 20241026095416_initial_model.sql (14.56ms)7862026/09/20 16:24:15 OK 20241026095416_initial_model.sql (46.98ms)7872026/09/20 16:24:15 OK 20241026095416_initial_model.sql (42.83ms)7882026/09/20 16:24:15 OK 20241026095416_initial_model.sql (45.32ms)7892026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)7902026-09-20 16:24:15.368 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367912026-09-20 16:24:15.368 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026/09/20 16:24:15 OK 20241026095416_initial_model.sql (50.52ms)7932026/09/20 16:24:15 OK 20241026095416_initial_model.sql (15.86ms)7942026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (4.91ms)7952026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (5.49ms)7962026/09/20 16:24:15 OK 20251218171726_add_pins.sql (4.62ms)7972026-09-20 16:24:15.372 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367982026-09-20 16:24:15.372 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026/09/20 16:24:15 OK 20241026095416_initial_model.sql (17.64ms)8002026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (5.04ms)8012026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)8022026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (4.38ms)8032026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)8042026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.9ms)8052026/09/20 16:24:15 OK 20251218171726_add_pins.sql (5.1ms)8062026/09/20 16:24:15 OK 20241026095416_initial_model.sql (15.19ms)8072026-09-20 16:24:15.379 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368082026-09-20 16:24:15.379 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026/09/20 16:24:15 OK 20251218171726_add_pins.sql (5.38ms)8102026/09/20 16:24:15 OK 20251218171726_add_pins.sql (9.18ms)8112026/09/20 16:24:15 OK 20251218171726_add_pins.sql (9.42ms)8122026/09/20 16:24:15 OK 20260905000000_add_claims.sql (4.19ms)8132026/09/20 16:24:15 OK 20251218171726_add_pins.sql (8.82ms)8142026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)8152026/09/20 16:24:15 OK 20251218171726_add_pins.sql (9.24ms)8162026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)8172026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (4.74ms)8182026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008192026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (6.31ms)8202026/09/20 16:24:15 OK 20251218171726_add_pins.sql (6.01ms)8212026-09-20 16:24:15.388 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368222026-09-20 16:24:15.388 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026/09/20 16:24:15 OK 20260905000000_add_claims.sql (12ms)8242026/09/20 16:24:15 OK 20241026095416_initial_model.sql (25.35ms)8252026/09/20 16:24:15 OK 1_commit_pending_closure.sql (14.13ms)8262026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (17.6ms)8272026/09/20 16:24:15 OK 20241026095416_initial_model.sql (18.79ms)8282026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (12.73ms)8292026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (19.19ms)8302026/09/20 16:24:15 OK 20241026095416_initial_model.sql (25.55ms)8312026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (20.16ms)8322026/09/20 16:24:15 OK 20260905000000_add_claims.sql (13.88ms)8332026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (19.97ms)8342026/09/20 16:24:15 OK 20241026095416_initial_model.sql (13.82ms)8352026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (5.51ms)8362026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (6.49ms)8372026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008382026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)8392026/09/20 16:24:15 OK 2_object_stats_trigger.sql (4.46ms)8402026/09/20 16:24:15 goose: up to current file version: 28412026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)8422026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)8432026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.96ms)8442026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (4.67ms)8452026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008462026/09/20 16:24:15 OK 20260905000000_add_claims.sql (6.16ms)8472026/09/20 16:24:15 OK 20260905000000_add_claims.sql (6.29ms)8482026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.33ms)8492026/09/20 16:24:15 goose: up to current file version: 28502026/09/20 16:24:15 OK 20251218171726_add_pins.sql (6.41ms)8512026/09/20 16:24:15 OK 20260905000000_add_claims.sql (8.64ms)8522026/09/20 16:24:15 OK 20260905000000_add_claims.sql (9.61ms)8532026/09/20 16:24:15 OK 20251218171726_add_pins.sql (6.11ms)8542026/09/20 16:24:15 OK 20260905000000_add_claims.sql (8.61ms)8552026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (3.22ms)8562026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008572026/09/20 16:24:15 OK 1_commit_pending_closure.sql (4.72ms)8582026/09/20 16:24:15 OK 20251218171726_add_pins.sql (5.44ms)8592026-09-20 16:24:15.411 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368602026-09-20 16:24:15.411 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8612026/09/20 16:24:15 OK 20251218171726_add_pins.sql (5.65ms)8622026-09-20 16:24:15.411 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368632026-09-20 16:24:15.411 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8642026-09-20 16:24:15.412 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368652026-09-20 16:24:15.412 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8662026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (5.15ms)8672026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008682026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.92ms)8692026/09/20 16:24:15 goose: up to current file version: 28702026/09/20 16:24:15 OK 1_commit_pending_closure.sql (4.71ms)8712026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (6.58ms)8722026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (6.87ms)8732026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008742026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (6.99ms)8752026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008762026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (6.08ms)8772026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (7.31ms)8782026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008792026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)8802026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (7.08ms)8812026/09/20 16:24:15 OK 2_object_stats_trigger.sql (3.13ms)8822026/09/20 16:24:15 goose: up to current file version: 28832026/09/20 16:24:15 OK 1_commit_pending_closure.sql (6.18ms)8842026/09/20 16:24:15 OK 20241026095416_initial_model.sql (19.15ms)8852026/09/20 16:24:15 OK 20260905000000_add_claims.sql (6.18ms)8862026/09/20 16:24:15 OK 2_object_stats_trigger.sql (4.27ms)8872026/09/20 16:24:15 goose: up to current file version: 28882026/09/20 16:24:15 OK 1_commit_pending_closure.sql (5.88ms)8892026/09/20 16:24:15 OK 20260905000000_add_claims.sql (5.8ms)8902026/09/20 16:24:15 OK 1_commit_pending_closure.sql (5.66ms)8912026/09/20 16:24:15 OK 20260905000000_add_claims.sql (5.53ms)8922026/09/20 16:24:15 OK 1_commit_pending_closure.sql (6.15ms)8932026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)8942026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (3.74ms)8952026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000008962026/09/20 16:24:15 OK 2_object_stats_trigger.sql (3.25ms)8972026/09/20 16:24:15 goose: up to current file version: 28982026/09/20 16:24:15 OK 20260905000000_add_claims.sql (8.67ms)8992026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (3.64ms)9002026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000009012026/09/20 16:24:15 OK 2_object_stats_trigger.sql (4.62ms)9022026/09/20 16:24:15 goose: up to current file version: 29032026/09/20 16:24:15 OK 2_object_stats_trigger.sql (4.84ms)9042026/09/20 16:24:15 goose: up to current file version: 29052026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (5.78ms)9062026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000009072026/09/20 16:24:15 OK 1_commit_pending_closure.sql (3.94ms)9082026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures9092026/09/20 16:24:15 OK 20251218171726_add_pins.sql (7ms)9102026/09/20 16:24:15 OK 1_commit_pending_closure.sql (3.34ms)9112026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (4.66ms)9122026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000009132026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.78ms)9142026/09/20 16:24:15 goose: up to current file version: 29152026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.3ms)9162026/09/20 16:24:15 goose: up to current file version: 29172026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.76ms)9182026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.56ms)9192026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.84ms)9202026/09/20 16:24:15 goose: up to current file version: 29212026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)9222026/09/20 16:24:15 OK 20241026095416_initial_model.sql (13.05ms)9232026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.99ms)9242026/09/20 16:24:15 goose: up to current file version: 29252026/09/20 16:24:15 OK 20241026095416_initial_model.sql (15.42ms)9262026/09/20 16:24:15 OK 20241026095416_initial_model.sql (15.57ms)9272026-09-20 16:24:15.442 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369282026-09-20 16:24:15.442 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (8.95ms)9302026/09/20 16:24:15 OK 20260905000000_add_claims.sql (12.06ms)9312026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (11.62ms)9322026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (11.54ms)9332026/09/20 16:24:15 OK 20251218171726_add_pins.sql (4.36ms)9342026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (3.35ms)9352026/09/20 16:24:15 goose: successfully migrated database to version: 20260920000000936--- PASS: TestReadProxyInvalidPath (0.45s)937=== CONT TestServerTLSConfig938=== RUN TestServerTLSConfig/no_client_CA939=== PAUSE TestServerTLSConfig/no_client_CA940=== RUN TestServerTLSConfig/missing_CA_file941=== PAUSE TestServerTLSConfig/missing_CA_file942=== RUN TestServerTLSConfig/not_a_PEM_file943=== PAUSE TestServerTLSConfig/not_a_PEM_file944=== CONT TestService_NativeMTLS9452026/09/20 16:24:15 OK 20251218171726_add_pins.sql (4ms)9462026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)9472026/09/20 16:24:15 OK 20251218171726_add_pins.sql (4.9ms)9482026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.58ms)9492026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.9ms)9502026/09/20 16:24:15 goose: up to current file version: 29512026-09-20 16:24:15.456 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369522026-09-20 16:24:15.456 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9532026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.15ms)9542026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4ms)9552026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)9562026-09-20 16:24:15.457 UTC [661] ERROR: relation "goose_db_version" does not exist at character 369572026-09-20 16:24:15.457 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026/09/20 16:24:15 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9592026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures9602026/09/20 16:24:15 OK 20241026095416_initial_model.sql (8.68ms)9612026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.07ms)9622026/09/20 16:24:15 goose: successfully migrated database to version: 20260920000000963--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.47s)9642026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.53ms)965=== CONT TestMetricsInventory9662026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.3ms)9672026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)9682026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.92ms)9692026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.07ms)9702026/09/20 16:24:15 goose: up to current file version: 29712026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.21ms)9722026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000009732026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.34ms)9742026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000009752026-09-20 16:24:15.464 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369762026-09-20 16:24:15.464 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9772026/09/20 16:24:15 OK 20251218171726_add_pins.sql (2.92ms)9782026-09-20 16:24:15.464 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369792026-09-20 16:24:15.464 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9802026-09-20 16:24:15.465 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369812026-09-20 16:24:15.465 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9822026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.95ms)9832026/09/20 16:24:15 OK 1_commit_pending_closure.sql (3.54ms)9842026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.38ms)9852026/09/20 16:24:15 goose: up to current file version: 29862026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)9872026-09-20 16:24:15.468 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369882026-09-20 16:24:15.468 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9892026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.61ms)9902026-09-20 16:24:15.469 UTC [669] ERROR: relation "goose_db_version" does not exist at character 369912026-09-20 16:24:15.469 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9922026/09/20 16:24:15 goose: up to current file version: 29932026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures9942026/09/20 16:24:15 OK 20241026095416_initial_model.sql (9.43ms)9952026/09/20 16:24:15 OK 20241026095416_initial_model.sql (9.87ms)9962026/09/20 16:24:15 OK 20260905000000_add_claims.sql (4.11ms)9972026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)9982026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)9992026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.74ms)10002026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010012026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.25ms)10022026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.74ms)10032026/09/20 16:24:15 OK 20251218171726_add_pins.sql (4.11ms)10042026/09/20 16:24:15 OK 20241026095416_initial_model.sql (9.12ms)10052026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.85ms)10062026/09/20 16:24:15 goose: up to current file version: 210072026/09/20 16:24:15 OK 20241026095416_initial_model.sql (9.17ms)10082026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)10092026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)10102026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)10112026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)10122026/09/20 16:24:15 OK 20241026095416_initial_model.sql (10.47ms)10132026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.47ms)10142026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.69ms)10152026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.83ms)10162026/09/20 16:24:15 OK 20241026095416_initial_model.sql (11ms)10172026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.87ms)10182026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)10192026/09/20 16:24:15 OK 20241026095416_initial_model.sql (12.26ms)10202026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.85ms)10212026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010222026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)10232026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.55ms)10242026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010252026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)10262026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.41ms)10272026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)10282026/09/20 16:24:15 OK 20251218171726_add_pins.sql (4.13ms)10292026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)10302026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.74ms)10312026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.29ms)10322026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.26ms)10332026/09/20 16:24:15 goose: up to current file version: 210342026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.49ms)10352026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.96ms)10362026/09/20 16:24:15 goose: up to current file version: 210372026/09/20 16:24:15 OK 20260905000000_add_claims.sql (4.06ms)10382026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.94ms)10392026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)10402026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)10412026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (3.16ms)10422026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010432026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.4ms)10442026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010452026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.07ms)10462026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.22ms)10472026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)10482026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.03ms)10492026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.77ms)10502026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (1.83ms)10512026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010522026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.09ms)10532026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010542026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.28ms)10552026/09/20 16:24:15 goose: up to current file version: 210562026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.73ms)10572026/09/20 16:24:15 goose: up to current file version: 210582026/09/20 16:24:15 OK 20260905000000_add_claims.sql (2.88ms)1059--- PASS: TestReadProxyDisabled (0.50s)1060=== CONT TestNARDeduplicationMetadataUploadBug10612026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.97ms)10622026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.23ms)10632026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.23ms)10642026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000010652026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.43ms)10662026/09/20 16:24:15 goose: up to current file version: 210672026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.21ms)10682026/09/20 16:24:15 goose: up to current file version: 210692026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.72ms)10702026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.43ms)10712026/09/20 16:24:15 goose: up to current file version: 210722026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures10732026/09/20 16:24:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1074--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)1075=== CONT TestCreatePendingClosureRejectsOversizedNAR10762026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures1077--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1078=== CONT TestCacheConfigHandlerMaxNarSize1079--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1080=== CONT TestGenerateLandingPage10812026/09/20 16:24:15 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1082--- PASS: TestCompleteMultipartUnregistered (0.56s)1083=== CONT TestService_readinessHandler1084--- PASS: TestGenerateLandingPage (0.00s)1085=== CONT TestService_healthCheckHandler10862026-09-20 16:24:15.555 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3610872026-09-20 16:24:15.555 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026-09-20 16:24:15.556 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3610892026-09-20 16:24:15.556 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10902026/09/20 16:24:15 OK 20241026095416_initial_model.sql (8.2ms)10912026/09/20 16:24:15 OK 20241026095416_initial_model.sql (8.71ms)10922026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)10932026/09/20 16:24:15 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"10942026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)1095--- PASS: TestService_AuthMiddleware (0.58s)1096=== CONT TestGracefulShutdownDrainsInflight10972026/09/20 16:24:15 INFO Starting HTTP server address=127.0.0.1:3429910982026/09/20 16:24:15 INFO Shutdown signal received, draining in-flight requests timeout=10s10992026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.3ms)11002026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.53ms)11012026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)11022026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (2.93ms)11032026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.86ms)11042026/09/20 16:24:15 OK 20260905000000_add_claims.sql (4.21ms)11052026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.55ms)11062026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000011072026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2ms)11082026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000011092026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.56ms)11102026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.22ms)11112026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.31ms)11122026/09/20 16:24:15 goose: up to current file version: 211132026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.13ms)11142026/09/20 16:24:15 goose: up to current file version: 211152026-09-20 16:24:15.591 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3611162026-09-20 16:24:15.591 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1117--- PASS: TestReadProxy404 (0.61s)1118=== CONT TestGCTaskStore_Fail1119--- PASS: TestGCTaskStore_Fail (0.00s)1120=== CONT TestGCTaskStore_PhaseUpdates1121--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1122=== CONT TestGCTaskStore_CompletedAllowsNewTask1123--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1124=== CONT TestParseSize1125--- PASS: TestParseSize (0.00s)1126=== CONT TestRedundantMultipartUpload11272026/09/20 16:24:15 OK 20241026095416_initial_model.sql (9.35ms)11282026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)11292026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.05ms)11302026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)11312026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.39ms)11322026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.44ms)11332026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000011342026/09/20 16:24:15 INFO Received cleanup request method=DELETE path=/api/pending_closures11352026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.71ms)11362026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.8ms)11372026/09/20 16:24:15 goose: up to current file version: 211382026/09/20 16:24:15 INFO Aborted multipart uploads count=011392026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures11402026-09-20 16:24:15.638 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3611412026-09-20 16:24:15.638 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11422026/09/20 16:24:15 INFO Received cleanup request method=DELETE path=/api/pending_closures11432026-09-20 16:24:15.640 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3611442026-09-20 16:24:15.640 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11452026/09/20 16:24:15 INFO Aborted multipart uploads count=111462026/09/20 16:24:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1147--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1148=== CONT TestCompletedNarNotReofferedAcrossClosures11492026-09-20 16:24:15.645 UTC [649] ERROR: Closure does not exist: id=111502026-09-20 16:24:15.645 UTC [649] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11512026-09-20 16:24:15.645 UTC [649] STATEMENT: -- name: CommitPendingClosure :exec1152 SELECT commit_pending_closure($1::bigint)1153 1154--- PASS: TestService_cleanupPendingClosuresHandler (0.65s)1155=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1156--- PASS: TestService_Rustfstest (0.66s)1157=== CONT TestReadRedirectUsesPublicS3URL11582026/09/20 16:24:15 OK 20241026095416_initial_model.sql (7.96ms)11592026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)11602026/09/20 16:24:15 OK 20241026095416_initial_model.sql (7.78ms)11612026/09/20 16:24:15 OK 20251218171726_add_pins.sql (2.88ms)11622026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)11632026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.38ms)11642026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (11.32ms)11652026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (9.93ms)11662026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.92ms)11672026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures11682026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures11692026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures11702026/09/20 16:24:15 OK 20260905000000_add_claims.sql (2.95ms)11712026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.06ms)11722026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000011732026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.19ms)11742026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000011752026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.37ms)11762026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.68ms)11772026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.91ms)11782026/09/20 16:24:15 goose: up to current file version: 211792026/09/20 16:24:15 OK 2_object_stats_trigger.sql (2.2ms)11802026/09/20 16:24:15 goose: up to current file version: 211812026-09-20 16:24:15.689 UTC [690] ERROR: relation "goose_db_version" does not exist at character 3611822026-09-20 16:24:15.689 UTC [690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11832026/09/20 16:24:15 OK 20241026095416_initial_model.sql (10.89ms)1184--- PASS: TestReadRedirectNar (0.71s)11852026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)1186=== CONT TestClientWithDependencies11872026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.33ms)11882026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)11892026/09/20 16:24:15 OK 20260905000000_add_claims.sql (2.98ms)11902026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (3.31ms)11912026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000011922026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.49ms)11932026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.35ms)11942026/09/20 16:24:15 goose: up to current file version: 211952026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures11962026-09-20 16:24:15.743 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3611972026-09-20 16:24:15.743 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11982026-09-20 16:24:15.744 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3611992026-09-20 16:24:15.744 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12002026-09-20 16:24:15.745 UTC [695] ERROR: relation "goose_db_version" does not exist at character 3612012026-09-20 16:24:15.745 UTC [695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1202--- PASS: TestReadProxyNarStreaming (0.76s)1203=== CONT TestGCTaskStore_GetEmpty1204--- PASS: TestGCTaskStore_GetEmpty (0.00s)1205=== CONT TestGCTaskStore_ConflictDifferentParams1206--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1207=== CONT TestGCTaskStore_DeduplicateSameParams1208--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1209=== CONT TestGCTaskStore_StartNew1210--- PASS: TestGCTaskStore_StartNew (0.00s)1211=== CONT TestGCMetrics12122026/09/20 16:24:15 OK 20241026095416_initial_model.sql (15.52ms)12132026/09/20 16:24:15 OK 20241026095416_initial_model.sql (17.55ms)12142026/09/20 16:24:15 OK 20241026095416_initial_model.sql (16.55ms)12152026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)12162026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)12172026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)12182026/09/20 16:24:15 OK 20251218171726_add_pins.sql (2.89ms)12192026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.27ms)12202026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.36ms)12212026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)12222026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (2.66ms)12232026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (2.77ms)12242026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.24ms)12252026/09/20 16:24:15 OK 20260905000000_add_claims.sql (2.97ms)12262026/09/20 16:24:15 OK 20260905000000_add_claims.sql (2.88ms)12272026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (1.84ms)12282026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000012292026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.33ms)12302026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000012312026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.44ms)12322026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000012332026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.98ms)12342026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.57ms)12352026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.68ms)12362026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.13ms)12372026/09/20 16:24:15 goose: up to current file version: 212382026/09/20 16:24:15 OK 2_object_stats_trigger.sql (927.65µs)12392026/09/20 16:24:15 goose: up to current file version: 212402026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.01ms)12412026/09/20 16:24:15 goose: up to current file version: 21242--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.79s)1243=== CONT TestGCBugBareHashReferences12442026-09-20 16:24:15.788 UTC [699] ERROR: relation "goose_db_version" does not exist at character 3612452026-09-20 16:24:15.788 UTC [699] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026/09/20 16:24:15 OK 20241026095416_initial_model.sql (8.07ms)12472026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)12482026/09/20 16:24:15 OK 20251218171726_add_pins.sql (2.95ms)12492026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)12502026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.25ms)12512026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.37ms)12522026/09/20 16:24:15 goose: successfully migrated database to version: 202609200000001253--- PASS: TestReadProxyNarinfo (0.81s)1254=== CONT TestLeadEndsOnShutdown12552026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.48ms)12562026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.43ms)12572026/09/20 16:24:15 goose: up to current file version: 212582026/09/20 16:24:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1259--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.83s)1260=== CONT TestLeadElectsOneAndHandsOver12612026-09-20 16:24:15.854 UTC [706] ERROR: relation "goose_db_version" does not exist at character 3612622026-09-20 16:24:15.854 UTC [706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1263--- PASS: TestReadProxyHead (0.67s)1264=== CONT TestResolveDBConnectionString12652026/09/20 16:24:15 OK 20241026095416_initial_model.sql (8.31ms)1266=== RUN TestResolveDBConnectionString/flag_wins1267=== PAUSE TestResolveDBConnectionString/flag_wins1268=== RUN TestResolveDBConnectionString/file_when_flag_empty1269=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1270=== RUN TestResolveDBConnectionString/missing_file_is_an_error1271=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1272=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1273=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1274=== RUN TestResolveDBConnectionString/nothing_configured1275=== PAUSE TestResolveDBConnectionString/nothing_configured1276=== CONT TestPinProtectsFromGC12772026-09-20 16:24:15.869 UTC [707] ERROR: relation "goose_db_version" does not exist at character 3612782026-09-20 16:24:15.869 UTC [707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)12802026/09/20 16:24:15 OK 20251218171726_add_pins.sql (2.68ms)12812026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (9.89ms)12822026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.58ms)12832026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (3.3ms)12842026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000012852026/09/20 16:24:15 OK 20241026095416_initial_model.sql (9.06ms)12862026/09/20 16:24:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12872026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)12882026/09/20 16:24:15 OK 1_commit_pending_closure.sql (3.71ms)12892026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.96ms)12902026/09/20 16:24:15 goose: up to current file version: 21291--- PASS: TestReadRedirectKeepsNarinfoProxied (0.69s)12922026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.87ms)1293=== CONT TestClientSharedPathCommittedMidPush12942026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)12952026-09-20 16:24:15.902 UTC [710] ERROR: relation "goose_db_version" does not exist at character 3612962026-09-20 16:24:15.902 UTC [710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12972026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.17ms)12982026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.52ms)12992026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000013002026/09/20 16:24:15 OK 1_commit_pending_closure.sql (2.12ms)13012026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.91ms)13022026/09/20 16:24:15 goose: up to current file version: 213032026/09/20 16:24:15 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Njg1YTE1Y2EtZjI1YS00MmQzLTlkY2ItNjExODUyNjQ4YTBhLjg4ZjRhY2I4LTlhMmYtNGFiZC05NjRjLTEyZTVmMjAzYjI5NXgxNzg5OTIxNDU1NDgxNjQyNjI2 parts=1013042026/09/20 16:24:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13052026/09/20 16:24:15 OK 20241026095416_initial_model.sql (8.3ms)13062026/09/20 16:24:15 INFO Completed upload id=113072026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)13082026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures13092026/09/20 16:24:15 OK 20251218171726_add_pins.sql (2.84ms)13102026/09/20 16:24:15 INFO Received uploads request method=POST path=/api/pending_closures13112026/09/20 16:24:15 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13122026/09/20 16:24:15 WARN Found objects in DB but missing from S3, will re-upload count=113132026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)13142026-09-20 16:24:15.927 UTC [726] ERROR: relation "goose_db_version" does not exist at character 3613152026-09-20 16:24:15.927 UTC [726] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1316--- PASS: TestService_verifyS3Integrity (0.93s)1317=== CONT TestReadProxyConditionalGet13182026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.15ms)13192026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (2.57ms)13202026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000013212026/09/20 16:24:15 OK 1_commit_pending_closure.sql (1.95ms)13222026/09/20 16:24:15 OK 2_object_stats_trigger.sql (1.42ms)13232026/09/20 16:24:15 goose: up to current file version: 213242026/09/20 16:24:15 OK 20241026095416_initial_model.sql (7.6ms)13252026/09/20 16:24:15 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)13262026/09/20 16:24:15 OK 20251218171726_add_pins.sql (3.01ms)13272026/09/20 16:24:15 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)13282026/09/20 16:24:15 OK 20260905000000_add_claims.sql (3.74ms)13292026/09/20 16:24:15 OK 20260920000000_drop_claims.sql (5ms)13302026/09/20 16:24:15 goose: successfully migrated database to version: 2026092000000013312026-09-20 16:24:15.973 UTC [729] ERROR: relation "goose_db_version" does not exist at character 3613322026-09-20 16:24:15.973 UTC [729] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13332026/09/20 16:24:15 OK 1_commit_pending_closure.sql (15.45ms)13342026-09-20 16:24:16.002 UTC [730] ERROR: relation "goose_db_version" does not exist at character 3613352026-09-20 16:24:16.002 UTC [730] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13362026/09/20 16:24:16 OK 2_object_stats_trigger.sql (70.86ms)13372026/09/20 16:24:16 goose: up to current file version: 21338--- PASS: TestResurrectedObjectNotDeleted (0.84s)1339=== CONT TestReadProxyRangeRequest1340--- PASS: TestObjectStatsTrigger (0.84s)1341=== CONT TestCacheConfigHandler1342=== RUN TestCacheConfigHandler/full_config,_no_issuer1343=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1344=== RUN TestCacheConfigHandler/no_cache_url_configured1345=== PAUSE TestCacheConfigHandler/no_cache_url_configured1346=== RUN TestCacheConfigHandler/no_signing_keys1347=== PAUSE TestCacheConfigHandler/no_signing_keys1348=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1349=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1350=== CONT TestClientMultipleUploads13512026-09-20 16:24:16.061 UTC [734] ERROR: relation "goose_db_version" does not exist at character 3613522026-09-20 16:24:16.061 UTC [734] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13532026/09/20 16:24:16 OK 20241026095416_initial_model.sql (15.64ms)13542026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)13552026/09/20 16:24:16 OK 20241026095416_initial_model.sql (13.45ms)13562026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)13572026/09/20 16:24:16 OK 20251218171726_add_pins.sql (5.59ms)13582026/09/20 16:24:16 OK 20251218171726_add_pins.sql (4.49ms)13592026/09/20 16:24:16 OK 20241026095416_initial_model.sql (8.61ms)13602026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)13612026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (5.62ms)13622026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (6.91ms)13632026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.8ms)13642026/09/20 16:24:16 OK 20260905000000_add_claims.sql (4.39ms)13652026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)13662026/09/20 16:24:16 OK 20260905000000_add_claims.sql (5.03ms)13672026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (3.68ms)13682026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000013692026/09/20 16:24:16 OK 20260905000000_add_claims.sql (3.91ms)13702026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (4.53ms)13712026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000013722026/09/20 16:24:16 OK 1_commit_pending_closure.sql (3.61ms)13732026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (3.38ms)13742026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000013752026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.69ms)13762026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.35ms)13772026/09/20 16:24:16 goose: up to current file version: 213782026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.84ms)13792026/09/20 16:24:16 goose: up to current file version: 213802026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.53ms)13812026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.45ms)13822026/09/20 16:24:16 goose: up to current file version: 213832026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures13842026-09-20 16:24:16.136 UTC [736] ERROR: relation "goose_db_version" does not exist at character 3613852026-09-20 16:24:16.136 UTC [736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13862026-09-20 16:24:16.140 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3613872026-09-20 16:24:16.140 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13882026/09/20 16:24:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13892026/09/20 16:24:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1390--- PASS: TestService_NativeMTLS (0.69s)1391=== CONT TestClientIntegration13922026/09/20 16:24:16 OK 20241026095416_initial_model.sql (9.18ms)13932026/09/20 16:24:16 OK 20241026095416_initial_model.sql (6.62ms)13942026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)13952026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)13962026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.57ms)13972026/09/20 16:24:16 OK 20251218171726_add_pins.sql (4.19ms)13982026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)13992026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)14002026/09/20 16:24:16 OK 20260905000000_add_claims.sql (3.8ms)14012026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.62ms)14022026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000014032026/09/20 16:24:16 OK 20260905000000_add_claims.sql (3.93ms)14042026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.15ms)14052026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000014062026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.79ms)14072026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.38ms)14082026/09/20 16:24:16 goose: up to current file version: 214092026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.19ms)14102026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.34ms)14112026/09/20 16:24:16 goose: up to current file version: 214122026/09/20 16:24:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1413--- PASS: TestMetricsInventory (0.73s)1414=== CONT TestClientErrorHandling1415=== RUN TestClientErrorHandling/InvalidStorePath1416=== PAUSE TestClientErrorHandling/InvalidStorePath1417=== RUN TestClientErrorHandling/InvalidAuthToken1418=== PAUSE TestClientErrorHandling/InvalidAuthToken1419=== RUN TestClientErrorHandling/ServerNotAvailable1420=== PAUSE TestClientErrorHandling/ServerNotAvailable1421=== CONT TestClientCADerivations14222026/09/20 16:24:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Njg1YTE1Y2EtZjI1YS00MmQzLTlkY2ItNjExODUyNjQ4YTBhLjlmNDZkZjMwLWM5ZjgtNGZmZS05ZDQwLWE5NGY0YzUwYTY0NHgxNzg5OTIxNDU1NjgzMDI1MjU4 parts=1014232026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14242026/09/20 16:24:16 INFO Completed upload id=114252026/09/20 16:24:16 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014262026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures14272026-09-20 16:24:16.209 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3614282026-09-20 16:24:16.209 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14292026/09/20 16:24:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures14302026/09/20 16:24:16 WARN readiness check failed error="closed pool"1431--- PASS: TestService_readinessHandler (0.67s)1432=== CONT TestCacheStatsHandler14332026/09/20 16:24:16 INFO Aborted multipart uploads count=014342026/09/20 16:24:16 OK 20241026095416_initial_model.sql (7.72ms)14352026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)14362026/09/20 16:24:16 OK 20251218171726_add_pins.sql (4.11ms)14372026/09/20 16:24:16 INFO Received cleanup request method=DELETE path=/api/pending_closures14382026/09/20 16:24:16 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=014392026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)14402026/09/20 16:24:16 INFO Aborted multipart uploads count=114412026/09/20 16:24:16 INFO Vacuumed table table=pending_closures14422026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.65ms)14432026/09/20 16:24:16 INFO Vacuumed table table=pending_objects14442026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.74ms)14452026/09/20 16:24:16 goose: successfully migrated database to version: 202609200000001446=== NAME TestNARDeduplicationMetadataUploadBug1447 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2434385709/001/store/rk0vramdqqh4accvrp1h2ss2l4f8bzrk-file1.txt1448--- PASS: TestMultipartCleanup (0.93s)14492026/09/20 16:24:16 INFO Vacuumed table table=multipart_uploads1450=== CONT TestService_AuthMiddleware_OIDC14512026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.59ms)1452--- PASS: TestService_healthCheckHandler (0.69s)1453=== CONT TestService_ReadScope_PublicByDefault14542026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.78ms)14552026/09/20 16:24:16 goose: up to current file version: 214562026/09/20 16:24:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33241/oidc14572026/09/20 16:24:16 INFO Vacuumed table table=closures14582026/09/20 16:24:16 INFO Vacuumed table table=objects14592026-09-20 16:24:16.266 UTC [768] ERROR: relation "goose_db_version" does not exist at character 3614602026-09-20 16:24:16.266 UTC [768] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14612026/09/20 16:24:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001462--- PASS: TestService_createPendingClosureHandler (1.27s)1463=== CONT TestService_RequireScope_OIDC14642026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures14652026/09/20 16:24:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44725/oidc14662026/09/20 16:24:16 OK 20241026095416_initial_model.sql (10.31ms)14672026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)14682026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures14692026/09/20 16:24:16 OK 20251218171726_add_pins.sql (3.83ms)14702026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.11ms)14712026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures14722026/09/20 16:24:16 OK 20260905000000_add_claims.sql (3.46ms)14732026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.51ms)14742026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000014752026/09/20 16:24:16 OK 1_commit_pending_closure.sql (3.31ms)14762026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.43ms)14772026/09/20 16:24:16 goose: up to current file version: 214782026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures14792026-09-20 16:24:16.323 UTC [807] ERROR: relation "goose_db_version" does not exist at character 3614802026-09-20 16:24:16.323 UTC [807] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14812026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14822026/09/20 16:24:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14832026/09/20 16:24:16 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Njg1YTE1Y2EtZjI1YS00MmQzLTlkY2ItNjExODUyNjQ4YTBhLjJjOWYyZjBhLTAzMWMtNDk2Ni05ZDFmLTBkNTA5YTU3OTM3OXgxNzg5OTIxNDU2MzA1Nzk0MDk314842026/09/20 16:24:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Njg1YTE1Y2EtZjI1YS00MmQzLTlkY2ItNjExODUyNjQ4YTBhLjJjOWYyZjBhLTAzMWMtNDk2Ni05ZDFmLTBkNTA5YTU3OTM3OXgxNzg5OTIxNDU2MzA1Nzk0MDk3 parts=11485--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.69s)1486=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14872026/09/20 16:24:16 OK 20241026095416_initial_model.sql (8.66ms)14882026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)14892026-09-20 16:24:16.346 UTC [810] ERROR: relation "goose_db_version" does not exist at character 3614902026-09-20 16:24:16.346 UTC [810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14912026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.63ms)14922026-09-20 16:24:16.349 UTC [812] ERROR: relation "goose_db_version" does not exist at character 3614932026-09-20 16:24:16.349 UTC [812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14942026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)1495--- PASS: TestReadRedirectUsesPublicS3URL (0.70s)1496=== CONT TestService_ReadAuthMiddleware14972026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.59ms)14982026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (3.4ms)14992026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000015002026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures15012026/09/20 16:24:16 OK 1_commit_pending_closure.sql (3.39ms)15022026/09/20 16:24:16 OK 20241026095416_initial_model.sql (9.42ms)15032026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.39ms)15042026/09/20 16:24:16 goose: up to current file version: 215052026/09/20 16:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15062026/09/20 16:24:16 INFO Uploading rk0vramdqqh4accvrp1h2ss2l4f8bzrk-file1.txt (160B)15072026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)15082026/09/20 16:24:16 OK 20241026095416_initial_model.sql (9.3ms)15092026/09/20 16:24:16 OK 20251218171726_add_pins.sql (3.21ms)15102026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)15112026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15122026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)15132026/09/20 16:24:16 OK 20251218171726_add_pins.sql (3.85ms)15142026/09/20 16:24:16 WARN Failed to register uploaded object key=rk0vramdqqh4accvrp1h2ss2l4f8bzrk.ls error="server returned 404: 404 page not found\n"15152026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15162026/09/20 16:24:16 INFO Signed narinfos id=1 count=115172026/09/20 16:24:16 INFO Uploading 1 narinfos15182026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.73ms)15192026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)15202026-09-20 16:24:16.376 UTC [833] ERROR: relation "goose_db_version" does not exist at character 3615212026-09-20 16:24:16.376 UTC [833] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15222026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.5ms)15232026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000015242026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15252026/09/20 16:24:16 WARN Failed to register uploaded object key=rk0vramdqqh4accvrp1h2ss2l4f8bzrk.narinfo error="server returned 404: 404 page not found\n"15262026/09/20 16:24:16 OK 20260905000000_add_claims.sql (3.03ms)15272026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.06ms)15282026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.34ms)15292026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000015302026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.76ms)15312026/09/20 16:24:16 goose: up to current file version: 215322026/09/20 16:24:16 INFO Completed upload id=115332026/09/20 16:24:16 INFO Upload complete. (98ms)15342026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.87ms)1535=== NAME TestNARDeduplicationMetadataUploadBug1536 metadata_upload_test.go:54: Retrieved narinfo from S3:1537 StorePath: /build/TestNARDeduplicationMetadataUploadBug2434385709/001/store/rk0vramdqqh4accvrp1h2ss2l4f8bzrk-file1.txt1538 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1539 Compression: zstd1540 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1541 NarSize: 1601542 References: 1543 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15442026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.87ms)15452026/09/20 16:24:16 goose: up to current file version: 21546 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1547 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1548 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15492026/09/20 16:24:16 OK 20241026095416_initial_model.sql (8.21ms)15502026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)1551=== NAME TestOrphanedObjectsGC1552 orphaned_objects_gc_test.go:290: GC Test Summary:1553 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1554 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1555 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1556 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1557 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1558--- PASS: TestOrphanedObjectsGC (1.18s)1559=== CONT TestService_AuthMiddleware_MTLSProxyHeader15602026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.19ms)15612026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (2.92ms)15622026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.96ms)15632026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.55ms)15642026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000015652026/09/20 16:24:16 INFO Aborted multipart uploads count=015662026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.34ms)15672026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.4ms)15682026/09/20 16:24:16 goose: up to current file version: 215692026/09/20 16:24:16 WARN Force mode enabled - objects will be deleted immediately without grace period15702026/09/20 16:24:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015712026/09/20 16:24:16 INFO Vacuumed table table=pending_closures15722026/09/20 16:24:16 INFO Vacuumed table table=pending_objects15732026/09/20 16:24:16 INFO Vacuumed table table=multipart_uploads15742026/09/20 16:24:16 INFO Vacuumed table table=closures15752026/09/20 16:24:16 INFO Vacuumed table table=objects1576--- PASS: TestGCMetrics (0.65s)1577=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15782026/09/20 16:24:16 INFO Received uploads request method=POST path=/1579=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15802026/09/20 16:24:16 INFO Received uploads request method=POST path=/1581=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15822026/09/20 16:24:16 INFO Received request for more parts method=POST path=/1583=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15842026/09/20 16:24:16 INFO Received complete multipart upload request method=POST path=/1585--- PASS: TestUploadHandlersRejectInvalidKeys (0.21s)1586 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1587 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1588 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1589 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1590=== CONT TestProxyWriteTimeout/narinfo1591=== CONT TestProxyWriteTimeout/10_GiB_nar1592=== CONT TestProxyWriteTimeout/unknown_size1593=== CONT TestProxyWriteTimeout/1_GiB_nar1594--- PASS: TestProxyWriteTimeout (0.21s)1595 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1596 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1597 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1598 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1599=== CONT TestIsValidUploadKey/narinfo1600=== CONT TestIsValidUploadKey/traversal_nar1601=== CONT TestIsValidUploadKey/traversal1602=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1603=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1604=== CONT TestIsValidUploadKey/build_log_plus_in_name1605=== CONT TestIsValidUploadKey/build_log_home-manager_file1606=== CONT TestIsValidUploadKey/build_log1607=== CONT TestIsValidUploadKey/listing1608=== CONT TestIsValidUploadKey/nar_plain1609=== CONT TestIsValidUploadKey/nar_xz1610=== CONT TestIsValidUploadKey/nar_zst1611=== CONT TestIsValidUploadKey/unknown_type1612=== CONT TestIsValidUploadKey/build_log_question_mark1613=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1614=== CONT TestIsValidUploadKey/index.html1615=== CONT TestIsValidUploadKey/nix-cache-info1616=== CONT TestIsValidUploadKey/realisation_plus_in_output1617=== CONT TestIsValidUploadKey/realisation1618=== CONT TestIsValidUploadKey/build_log_equals1619=== CONT TestIsValidUploadKey/empty_key1620=== CONT TestIsValidUploadKey/absolute1621--- PASS: TestIsValidUploadKey (0.21s)1622 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1623 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1624 --- PASS: TestIsValidUploadKey/traversal (0.00s)1625 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1626 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1627 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1628 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1629 --- PASS: TestIsValidUploadKey/build_log (0.00s)1630 --- PASS: TestIsValidUploadKey/listing (0.00s)1631 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1632 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1633 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1634 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1635 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1636 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1637 --- PASS: TestIsValidUploadKey/index.html (0.00s)1638 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1639 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1640 --- PASS: TestIsValidUploadKey/realisation (0.00s)1641 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1642 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1643 --- PASS: TestIsValidUploadKey/absolute (0.00s)1644=== CONT TestIsValidCachePath/narinfo1645=== CONT TestIsValidCachePath/traversal_parent1646=== CONT TestIsValidCachePath/short_hash1647=== CONT TestIsValidCachePath/wrong_extension1648=== CONT TestIsValidCachePath/leading_slash1649=== CONT TestIsValidCachePath/empty1650=== CONT TestIsValidCachePath/random_path1651=== CONT TestIsValidCachePath/invalid_char_u1652=== CONT TestIsValidCachePath/invalid_char_e1653=== CONT TestIsValidCachePath/traversal_in_middle1654=== CONT TestIsValidCachePath/nix-cache-info1655=== CONT TestIsValidCachePath/index.html1656=== CONT TestIsValidCachePath/nar_xz1657=== CONT TestIsValidCachePath/nar_uncompressed1658=== CONT TestIsValidCachePath/nar_bz21659=== CONT TestIsValidCachePath/realisation1660=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1661=== CONT TestIsValidCachePath/nar_zst1662=== CONT TestIsValidCachePath/log1663=== CONT TestIsValidCachePath/ls1664--- PASS: TestIsValidCachePath (0.20s)1665 --- PASS: TestIsValidCachePath/narinfo (0.00s)1666 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1667 --- PASS: TestIsValidCachePath/short_hash (0.00s)1668 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1669 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1670 --- PASS: TestIsValidCachePath/empty (0.00s)1671 --- PASS: TestIsValidCachePath/random_path (0.00s)1672 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1673 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1674 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1675 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1676 --- PASS: TestIsValidCachePath/index.html (0.00s)1677 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1678 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1679 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1680 --- PASS: TestIsValidCachePath/realisation (0.00s)1681 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1682 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1683 --- PASS: TestIsValidCachePath/log (0.00s)1684 --- PASS: TestIsValidCachePath/ls (0.00s)1685=== CONT TestParseSingleRange/none1686=== CONT TestParseSingleRange/end_clamped_to_size1687=== CONT TestParseSingleRange/start_far_past_EOF1688=== CONT TestParseSingleRange/start_past_EOF1689=== CONT TestParseSingleRange/single_byte1690=== CONT TestParseSingleRange/suffix_exceeds_size1691=== CONT TestParseSingleRange/suffix1692=== CONT TestParseSingleRange/malformed_both_empty1693=== CONT TestParseSingleRange/open-ended1694=== CONT TestParseSingleRange/closed1695=== CONT TestParseSingleRange/malformed_end_before_start1696=== CONT TestParseSingleRange/multi-range_ignored1697=== CONT TestParseSingleRange/malformed_no_dash1698=== CONT TestParseSingleRange/unknown_unit1699=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17002026/09/20 16:24:16 INFO Received request for more parts method=POST path=/1701--- PASS: TestParseSingleRange (0.00s)1702 --- PASS: TestParseSingleRange/none (0.00s)1703 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1704 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1705 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1706 --- PASS: TestParseSingleRange/single_byte (0.00s)1707 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1708 --- PASS: TestParseSingleRange/suffix (0.00s)1709 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1710 --- PASS: TestParseSingleRange/open-ended (0.00s)1711 --- PASS: TestParseSingleRange/closed (0.00s)1712 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1713 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1714 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1715 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1716=== NAME TestNARDeduplicationMetadataUploadBug1717 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2434385709/001/store/888bldwr1kbjbspqcnb8rndjj9dr7g8c-file2.txt17182026-09-20 16:24:16.426 UTC [881] ERROR: relation "goose_db_version" does not exist at character 3617192026-09-20 16:24:16.426 UTC [881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17202026-09-20 16:24:16.436 UTC [899] ERROR: relation "goose_db_version" does not exist at character 3617212026-09-20 16:24:16.436 UTC [899] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17222026/09/20 16:24:16 OK 20241026095416_initial_model.sql (9.3ms)17232026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)17242026/09/20 16:24:16 INFO lead: acquired remote=192.0.2.1:123417252026/09/20 16:24:16 INFO lead: released remote=192.0.2.1:12341726--- PASS: TestLeadEndsOnShutdown (0.63s)1727=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17282026/09/20 16:24:16 INFO Received complete multipart upload request method=POST path=/17292026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.86ms)17302026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)17312026/09/20 16:24:16 OK 20241026095416_initial_model.sql (8.76ms)1732=== NAME TestClientWithDependencies1733 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1389329045/001/store/w2za7w5x4sfvfky12hgdzxi99281q9iy-test-script17342026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.61ms)17352026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)17362026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.69ms)17372026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000017382026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.44ms)17392026/09/20 16:24:16 OK 1_commit_pending_closure.sql (2.58ms)17402026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)17412026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.39ms)17422026/09/20 16:24:16 goose: up to current file version: 217432026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.43ms)17442026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.11ms)17452026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000017462026/09/20 16:24:16 OK 1_commit_pending_closure.sql (1.62ms)17472026/09/20 16:24:16 OK 2_object_stats_trigger.sql (879.99µs)17482026/09/20 16:24:16 goose: up to current file version: 217492026/09/20 16:24:16 INFO lead: acquired remote=192.0.2.1:123417502026-09-20 16:24:16.474 UTC [920] ERROR: relation "goose_db_version" does not exist at character 3617512026-09-20 16:24:16.474 UTC [920] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1752 client_integration_test.go:615: Found 1 dependencies (including self)17532026/09/20 16:24:16 OK 20241026095416_initial_model.sql (6.98ms)17542026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)17552026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.1ms)1756=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17572026/09/20 16:24:16 INFO Received uploads request method=POST path=/17582026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (2.03ms)17592026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.58ms)17602026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17612026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (1.53ms)17622026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000017632026/09/20 16:24:16 OK 1_commit_pending_closure.sql (1.61ms)17642026/09/20 16:24:16 OK 2_object_stats_trigger.sql (649.94µs)17652026/09/20 16:24:16 goose: up to current file version: 21766=== CONT TestServerTLSConfig/no_client_CA1767=== CONT TestServerTLSConfig/not_a_PEM_file1768=== CONT TestServerTLSConfig/missing_CA_file1769--- PASS: TestServerTLSConfig (0.00s)1770 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1771 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1772 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1773=== CONT TestResolveDBConnectionString/flag_wins1774=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1775=== CONT TestResolveDBConnectionString/nothing_configured1776=== CONT TestResolveDBConnectionString/missing_file_is_an_error1777=== CONT TestResolveDBConnectionString/file_when_flag_empty1778=== CONT TestCacheConfigHandler/full_config,_no_issuer1779=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1780--- PASS: TestResolveDBConnectionString (0.00s)1781 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1782 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1783 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1784 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1785 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1786=== CONT TestCacheConfigHandler/no_signing_keys1787=== CONT TestCacheConfigHandler/no_cache_url_configured1788--- PASS: TestCacheConfigHandler (0.00s)1789 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1790 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1791 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1792 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1793=== CONT TestClientErrorHandling/InvalidStorePath17942026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures17952026/09/20 16:24:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17962026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17972026/09/20 16:24:16 WARN Failed to register uploaded object key=888bldwr1kbjbspqcnb8rndjj9dr7g8c.ls error="server returned 404: 404 page not found\n"17982026/09/20 16:24:16 INFO Signed narinfos id=2 count=117992026/09/20 16:24:16 INFO Uploading 1 narinfos18002026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18012026/09/20 16:24:16 WARN Failed to register uploaded object key=888bldwr1kbjbspqcnb8rndjj9dr7g8c.narinfo error="server returned 404: 404 page not found\n"18022026/09/20 16:24:16 INFO Completed upload id=218032026/09/20 16:24:16 INFO Upload complete. (79ms)1804=== NAME TestNARDeduplicationMetadataUploadBug1805 metadata_upload_test.go:76: Retrieved narinfo from S3:1806 StorePath: /build/TestNARDeduplicationMetadataUploadBug2434385709/001/store/888bldwr1kbjbspqcnb8rndjj9dr7g8c-file2.txt1807 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1808 Compression: zstd1809 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1810 NarSize: 1601811 References: 1812 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1813 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1814 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1815 {"version":1,"root":{"type":"regular","size":44}}1816--- PASS: TestReadProxyConditionalGet (0.62s)1817=== CONT TestClientErrorHandling/ServerNotAvailable1818--- PASS: TestNARDeduplicationMetadataUploadBug (1.05s)1819=== CONT TestClientErrorHandling/InvalidAuthToken18202026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18212026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures18222026/09/20 16:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18232026/09/20 16:24:16 INFO Uploading w2za7w5x4sfvfky12hgdzxi99281q9iy-test-script (136B)18242026/09/20 16:24:16 WARN Failed to register uploaded object key=log/inxyacqyhr96qp6sdrs95dykl6bpb0w3-test-script.drv error="server returned 404: 404 page not found\n"1825--- PASS: TestReadProxyRangeRequest (0.52s)18262026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18272026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18282026/09/20 16:24:16 WARN Failed to register uploaded object key=w2za7w5x4sfvfky12hgdzxi99281q9iy.ls error="server returned 404: 404 page not found\n"18292026/09/20 16:24:16 INFO Signed narinfos id=1 count=118302026/09/20 16:24:16 INFO Uploading 1 narinfos18312026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18322026/09/20 16:24:16 WARN Failed to register uploaded object key=w2za7w5x4sfvfky12hgdzxi99281q9iy.narinfo error="server returned 404: 404 page not found\n"18332026-09-20 16:24:16.577 UTC [1083] ERROR: relation "goose_db_version" does not exist at character 3618342026-09-20 16:24:16.577 UTC [1083] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18352026/09/20 16:24:16 INFO Completed upload id=118362026/09/20 16:24:16 INFO Upload complete. (64ms)1837=== NAME TestClientWithDependencies1838 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1389329045/001/store) requires matching store prefix1839--- PASS: TestClientWithDependencies (0.88s)18402026/09/20 16:24:16 OK 20241026095416_initial_model.sql (7.22ms)18412026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)18422026/09/20 16:24:16 OK 20251218171726_add_pins.sql (1.93ms)1843=== NAME TestPinProtectsFromGC1844 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2398720181/001/store/nj3ap5a9hqk49qn1z7byz7n4snhbq0vb-pinned-file.txt1845 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2398720181/001/store/79125sk99x6pas9cjng7p7dv0hcr0b3a-unpinned-file.txt18462026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (2.46ms)18472026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.82ms)18482026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (2.79ms)18492026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000018502026/09/20 16:24:16 OK 1_commit_pending_closure.sql (1.99ms)18512026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.53ms)18522026/09/20 16:24:16 goose: up to current file version: 218532026/09/20 16:24:16 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/present18542026/09/20 16:24:16 INFO lead: released remote=192.0.2.1:12341855=== NAME TestClientMultipleUploads1856 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3091093921/001/store/f5ifmca2shv82j17kgyfmmsa623wkshd-test-file-0.txt18572026-09-20 16:24:16.631 UTC [1190] ERROR: relation "goose_db_version" does not exist at character 3618582026-09-20 16:24:16.631 UTC [1190] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18592026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1860=== NAME TestClientIntegration1861 client_integration_test.go:286: Created store path: /build/TestClientIntegration2062956763/002/store/zdsh1b6ahg3wlab7il9bxm3fhl28wav5-test-file.txt18622026/09/20 16:24:16 OK 20241026095416_initial_model.sql (7.14ms)18632026/09/20 16:24:16 OK 20251210153512_drop_unused_gin_index.sql (987.59µs)18642026/09/20 16:24:16 OK 20251218171726_add_pins.sql (2.34ms)1865--- PASS: TestCacheStatsHandler (0.42s)18662026/09/20 16:24:16 OK 20260628120000_add_object_size_and_stats.sql (1.85ms)18672026/09/20 16:24:16 OK 20260905000000_add_claims.sql (2.16ms)1868--- PASS: TestGCBugBareHashReferences (0.86s)18692026/09/20 16:24:16 OK 20260920000000_drop_claims.sql (1.42ms)18702026/09/20 16:24:16 goose: successfully migrated database to version: 2026092000000018712026/09/20 16:24:16 OK 1_commit_pending_closure.sql (1.37ms)18722026/09/20 16:24:16 OK 2_object_stats_trigger.sql (1.14ms)18732026/09/20 16:24:16 goose: up to current file version: 21874--- PASS: TestService_ReadScope_PublicByDefault (0.41s)18752026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18762026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures18772026/09/20 16:24:16 INFO lead: acquired remote=192.0.2.1:123418782026/09/20 16:24:16 INFO lead: released remote=192.0.2.1:12341879=== NAME TestClientMultipleUploads1880 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3091093921/001/store/5nszpiv5whdkylw3qai4k1zyiyblyqlc-test-file-1.txt1881--- PASS: TestLeadElectsOneAndHandsOver (0.84s)1882=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1883=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1884=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1885=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1886=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1887=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1888=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1889=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1890=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1891=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1892=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1893=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured18942026/09/20 16:24:16 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]18952026/09/20 16:24:16 WARN Authentication failed token_preview=eyJhbGciOi...Eaqpg0oPvg token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1896--- PASS: TestService_AuthMiddleware_OIDC (0.43s)1897 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1898 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1899 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1900 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19012026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures19022026/09/20 16:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19032026/09/20 16:24:16 INFO Uploading nj3ap5a9hqk49qn1z7byz7n4snhbq0vb-pinned-file.txt (128B)1904=== RUN TestService_RequireScope_OIDC/builder_may_write1905=== PAUSE TestService_RequireScope_OIDC/builder_may_write1906=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1907=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1908=== RUN TestService_RequireScope_OIDC/ops_may_admin1909=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1910=== RUN TestService_RequireScope_OIDC/ops_may_not_write1911=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1912=== RUN TestService_RequireScope_OIDC/reader_may_not_write1913=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1914=== RUN TestService_RequireScope_OIDC/static_token_may_admin1915=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1916=== RUN TestService_RequireScope_OIDC/static_token_may_write1917=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1918=== RUN TestService_RequireScope_OIDC/reader_may_read1919=== PAUSE TestService_RequireScope_OIDC/reader_may_read1920=== RUN TestService_RequireScope_OIDC/writer_implies_read1921=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1922=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1923=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1924=== CONT TestService_RequireScope_OIDC/builder_may_write1925=== CONT TestService_RequireScope_OIDC/static_token_may_admin1926=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1927=== CONT TestService_RequireScope_OIDC/writer_implies_read1928=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1929=== CONT TestService_RequireScope_OIDC/ops_may_admin1930=== CONT TestService_RequireScope_OIDC/reader_may_read1931=== CONT TestService_RequireScope_OIDC/static_token_may_write1932=== CONT TestService_RequireScope_OIDC/ops_may_not_write1933=== CONT TestService_RequireScope_OIDC/reader_may_not_write1934=== NAME TestClientCADerivations1935 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations246774211/001/store/j8c4jlad509l350q55cpxp86b8n5y5zn-ca-test1936--- PASS: TestService_RequireScope_OIDC (0.44s)1937 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)19472026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1948=== NAME TestClientMultipleUploads1949 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3091093921/001/store/c737kpci9hf1njgl56150widfahf86wx-test-file-2.txt19502026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19512026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19522026/09/20 16:24:16 WARN Failed to register uploaded object key=nj3ap5a9hqk49qn1z7byz7n4snhbq0vb.ls error="server returned 404: 404 page not found\n"19532026/09/20 16:24:16 INFO Signed narinfos id=1 count=119542026/09/20 16:24:16 INFO Uploading 1 narinfos19552026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19562026/09/20 16:24:16 WARN Failed to register uploaded object key=nj3ap5a9hqk49qn1z7byz7n4snhbq0vb.narinfo error="server returned 404: 404 page not found\n"19572026/09/20 16:24:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.787785ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19582026/09/20 16:24:16 INFO Completed upload id=119592026/09/20 16:24:16 INFO Upload complete. (91ms)19602026/09/20 16:24:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19612026/09/20 16:24:16 WARN mTLS auth: bound subjects configured but subject DN unavailable19622026/09/20 16:24:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1963--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.38s)19642026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1965--- PASS: TestService_ReadAuthMiddleware (0.39s)1966=== NAME TestClientCADerivations1967 client_ca_test.go:139: Found 1 dependencies (including self)19682026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures19692026/09/20 16:24:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19702026/09/20 16:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19712026/09/20 16:24:16 INFO Uploading zdsh1b6ahg3wlab7il9bxm3fhl28wav5-test-file.txt (152B)19722026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19732026/09/20 16:24:16 WARN Failed to register uploaded object key=zdsh1b6ahg3wlab7il9bxm3fhl28wav5.ls error="server returned 404: 404 page not found\n"19742026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19752026/09/20 16:24:16 INFO Signed narinfos id=1 count=119762026/09/20 16:24:16 INFO Uploading 1 narinfos1977--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)19782026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19792026/09/20 16:24:16 WARN Failed to register uploaded object key=zdsh1b6ahg3wlab7il9bxm3fhl28wav5.narinfo error="server returned 404: 404 page not found\n"19802026/09/20 16:24:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Njg1YTE1Y2EtZjI1YS00MmQzLTlkY2ItNjExODUyNjQ4YTBhLmM5ZWZkMDZjLTE1OWQtNGNhYy04MTUxLTM4YTJlZjA2YzJjM3gxNzg5OTIxNDU2Mjg0MDkxMDg1 parts=121981--- PASS: TestRedundantMultipartUpload (1.16s)19822026/09/20 16:24:16 INFO Completed upload id=119832026/09/20 16:24:16 INFO Upload complete. (92ms)19842026/09/20 16:24:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19852026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures19862026/09/20 16:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19872026/09/20 16:24:16 INFO Uploading pb6v0waxa2p937k8795dv6h4gja14khs-shared-dep (136B)19882026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19892026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19902026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19912026/09/20 16:24:16 WARN Failed to register uploaded object key=pb6v0waxa2p937k8795dv6h4gja14khs.ls error="server returned 404: 404 page not found\n"19922026/09/20 16:24:16 INFO Signed narinfos id=2 count=119932026/09/20 16:24:16 INFO Uploading 1 narinfos19942026/09/20 16:24:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Njg1YTE1Y2EtZjI1YS00MmQzLTlkY2ItNjExODUyNjQ4YTBhLmNiY2IxZTIzLWYyYzgtNDYzYy1hYmZlLTNhNTgyMzNiNWJhNHgxNzg5OTIxNDU2MzM0NTUxOTYx parts=1219952026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures19962026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19972026/09/20 16:24:16 WARN Failed to register uploaded object key=pb6v0waxa2p937k8795dv6h4gja14khs.narinfo error="server returned 404: 404 page not found\n"1998--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.14s)19992026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20002026/09/20 16:24:16 INFO Completed upload id=220012026/09/20 16:24:16 INFO Upload complete. (87ms)20022026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures20032026/09/20 16:24:16 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20042026/09/20 16:24:16 INFO Uploading pb6v0waxa2p937k8795dv6h4gja14khs-shared-dep (136B)20052026/09/20 16:24:16 INFO Uploading cwyid5k0b59vd6famlgdf2cf67wa71dm-top (224B)20062026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20072026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/1ghb6a1vr764wrb5jvdz4zhhpx9n3jk3s6mjl8g1hk11pqjywz5d.nar.zst error="server returned 404: 404 page not found\n"20082026/09/20 16:24:16 INFO All 1 paths already cached20092026/09/20 16:24:16 WARN Failed to register uploaded object key=pb6v0waxa2p937k8795dv6h4gja14khs.ls error="server returned 404: 404 page not found\n"2010=== NAME TestClientIntegration2011 client_integration_test.go:312: Retrieved narinfo from S3:2012 StorePath: /build/TestClientIntegration2062956763/002/store/zdsh1b6ahg3wlab7il9bxm3fhl28wav5-test-file.txt2013 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2014 Compression: zstd2015 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12016 NarSize: 1522017 References: 2018 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk120192026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20202026/09/20 16:24:16 WARN Failed to register uploaded object key=cwyid5k0b59vd6famlgdf2cf67wa71dm.ls error="server returned 404: 404 page not found\n"2021 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)20222026/09/20 16:24:16 INFO Signed narinfos id=1 count=12023 client_integration_test.go:313: Decompressed .ls content (64 bytes):2024 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2025 client_integration_test.go:316: Testing garbage collection...20262026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20272026/09/20 16:24:16 INFO Signed narinfos id=3 count=120282026/09/20 16:24:16 INFO Uploading 2 narinfos20292026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20302026/09/20 16:24:16 WARN Failed to register uploaded object key=pb6v0waxa2p937k8795dv6h4gja14khs.narinfo error="server returned 404: 404 page not found\n"20312026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20322026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures20332026/09/20 16:24:16 WARN Failed to register uploaded object key=cwyid5k0b59vd6famlgdf2cf67wa71dm.narinfo error="server returned 404: 404 page not found\n"20342026/09/20 16:24:16 INFO Completed upload id=120352026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20362026/09/20 16:24:16 INFO Completed upload id=320372026/09/20 16:24:16 INFO Upload complete. (214ms)2038=== NAME TestClientSharedPathCommittedMidPush2039 client_integration_test.go:680: Retrieved narinfo from S3:2040 StorePath: /build/TestClientSharedPathCommittedMidPush2423002301/001/store/pb6v0waxa2p937k8795dv6h4gja14khs-shared-dep2041 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2042 Compression: zstd2043 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822044 NarSize: 1362045 References: 2046 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n20472026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures20482026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures2049 client_integration_test.go:680: Retrieved narinfo from S3:2050 StorePath: /build/TestClientSharedPathCommittedMidPush2423002301/001/store/cwyid5k0b59vd6famlgdf2cf67wa71dm-top2051 URL: nar/1ghb6a1vr764wrb5jvdz4zhhpx9n3jk3s6mjl8g1hk11pqjywz5d.nar.zst2052 Compression: zstd2053 NarHash: sha256:1ghb6a1vr764wrb5jvdz4zhhpx9n3jk3s6mjl8g1hk11pqjywz5d2054 NarSize: 2242055 References: /build/TestClientSharedPathCommittedMidPush2423002301/001/store/pb6v0waxa2p937k8795dv6h4gja14khs-shared-dep2056 CA: text:sha256:17zrk46q37hyvkg8qrwshdcc7wlfplqwlb0yjgpv9cgc4g9h943q20572026/09/20 16:24:16 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20582026/09/20 16:24:16 INFO Uploading 5nszpiv5whdkylw3qai4k1zyiyblyqlc-test-file-1.txt (160B)20592026/09/20 16:24:16 INFO Uploading c737kpci9hf1njgl56150widfahf86wx-test-file-2.txt (160B)20602026/09/20 16:24:16 INFO Uploading f5ifmca2shv82j17kgyfmmsa623wkshd-test-file-0.txt (160B)20612026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20622026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20632026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"2064--- PASS: TestClientSharedPathCommittedMidPush (0.92s)20652026/09/20 16:24:16 WARN Failed to register uploaded object key=5nszpiv5whdkylw3qai4k1zyiyblyqlc.ls error="server returned 404: 404 page not found\n"20662026/09/20 16:24:16 WARN Failed to register uploaded object key=c737kpci9hf1njgl56150widfahf86wx.ls error="server returned 404: 404 page not found\n"20672026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures20682026/09/20 16:24:16 WARN Failed to register uploaded object key=f5ifmca2shv82j17kgyfmmsa623wkshd.ls error="server returned 404: 404 page not found\n"20692026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20702026/09/20 16:24:16 INFO Signed narinfos id=2 count=120712026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20722026/09/20 16:24:16 INFO Signed narinfos id=3 count=120732026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20742026/09/20 16:24:16 INFO Signed narinfos id=1 count=120752026/09/20 16:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20762026/09/20 16:24:16 INFO Uploading 3 narinfos20772026/09/20 16:24:16 INFO Uploading 79125sk99x6pas9cjng7p7dv0hcr0b3a-unpinned-file.txt (128B)20782026/09/20 16:24:16 WARN Failed to register uploaded object key=f5ifmca2shv82j17kgyfmmsa623wkshd.narinfo error="server returned 404: 404 page not found\n"20792026/09/20 16:24:16 WARN Failed to register uploaded object key=c737kpci9hf1njgl56150widfahf86wx.narinfo error="server returned 404: 404 page not found\n"20802026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20812026/09/20 16:24:16 WARN Failed to register uploaded object key=5nszpiv5whdkylw3qai4k1zyiyblyqlc.narinfo error="server returned 404: 404 page not found\n"20822026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20832026/09/20 16:24:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures20842026/09/20 16:24:16 INFO Garbage collection started20852026/09/20 16:24:16 INFO Completed upload id=120862026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20872026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20882026/09/20 16:24:16 WARN Failed to register uploaded object key=79125sk99x6pas9cjng7p7dv0hcr0b3a.ls error="server returned 404: 404 page not found\n"20892026/09/20 16:24:16 INFO Signed narinfos id=2 count=120902026/09/20 16:24:16 INFO Uploading 1 narinfos20912026/09/20 16:24:16 INFO Completed upload id=220922026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20932026/09/20 16:24:16 INFO Completed upload id=320942026/09/20 16:24:16 INFO Upload complete. (96ms)2095=== NAME TestClientMultipleUploads2096 client_integration_test.go:369: Uploaded 3 paths in 126.680354ms20972026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20982026/09/20 16:24:16 WARN Failed to register uploaded object key=79125sk99x6pas9cjng7p7dv0hcr0b3a.narinfo error="server returned 404: 404 page not found\n"20992026/09/20 16:24:16 INFO Completed upload id=221002026/09/20 16:24:16 INFO Aborted multipart uploads count=021012026/09/20 16:24:16 INFO Upload complete. (85ms)21022026/09/20 16:24:16 WARN Force mode enabled - objects will be deleted immediately without grace period2103--- PASS: TestClientMultipleUploads (0.79s)21042026/09/20 16:24:16 INFO Received uploads request method=POST path=/api/pending_closures21052026/09/20 16:24:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21062026/09/20 16:24:16 INFO Uploading j8c4jlad509l350q55cpxp86b8n5y5zn-ca-test (144B)21072026/09/20 16:24:16 WARN Failed to register uploaded object key=log/azzgdc3fd76j0prwrhm99vqdi17r41i7-ca-test.drv error="server returned 404: 404 page not found\n"21082026/09/20 16:24:16 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21092026/09/20 16:24:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21102026/09/20 16:24:16 WARN Failed to register uploaded object key=j8c4jlad509l350q55cpxp86b8n5y5zn.ls error="server returned 404: 404 page not found\n"21112026/09/20 16:24:16 INFO Signed narinfos id=1 count=121122026/09/20 16:24:16 INFO Uploading 1 narinfos21132026/09/20 16:24:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21142026/09/20 16:24:16 INFO Received create pin request method=POST path=/api/pins/myapp21152026/09/20 16:24:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21162026/09/20 16:24:16 WARN Failed to register uploaded object key=j8c4jlad509l350q55cpxp86b8n5y5zn.narinfo error="server returned 404: 404 page not found\n"21172026/09/20 16:24:16 INFO Completed upload id=121182026/09/20 16:24:16 INFO Upload complete. (107ms)21192026/09/20 16:24:16 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2398720181/001/store/nj3ap5a9hqk49qn1z7byz7n4snhbq0vb-pinned-file.txt narinfo_key=nj3ap5a9hqk49qn1z7byz7n4snhbq0vb.narinfo21202026/09/20 16:24:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures21212026/09/20 16:24:16 INFO Garbage collection started2122=== NAME TestClientCADerivations2123 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations246774211/001/store/j8c4jlad509l350q55cpxp86b8n5y5zn-ca-test2124 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2125 Compression: zstd2126 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2127 NarSize: 1442128 References: 2129 Deriver: /build/TestClientCADerivations246774211/001/store/azzgdc3fd76j0prwrhm99vqdi17r41i7-ca-test.drv2130 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2131 client_ca_test.go:185: Checking for realisation files in S3...2132 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2133 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21342026/09/20 16:24:16 INFO Aborted multipart uploads count=021352026/09/20 16:24:16 WARN Force mode enabled - objects will be deleted immediately without grace period21362026/09/20 16:24:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21372026/09/20 16:24:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.82015ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21382026/09/20 16:24:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2139 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2140 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2141 error: binary cache 's3://bucket46?endpoint=http://localhost:38755®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations246774211/001/store'2142 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12143--- PASS: TestUploadHandlersRejectOversizedBody (0.33s)2144 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2145 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2146 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.65s)2147--- PASS: TestClientCADerivations (0.95s)21482026/09/20 16:24:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.658279ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2149=== NAME TestOrphanedObjectsGCStressTest2150 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2151 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21522026/09/20 16:24:17 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=021532026/09/20 16:24:17 INFO Vacuumed table table=pending_closures21542026/09/20 16:24:17 INFO Vacuumed table table=pending_objects21552026/09/20 16:24:17 INFO Vacuumed table table=multipart_uploads21562026/09/20 16:24:17 INFO Vacuumed table table=closures21572026/09/20 16:24:17 INFO Vacuumed table table=objects21582026/09/20 16:24:17 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=021592026/09/20 16:24:17 INFO Vacuumed table table=pending_closures21602026/09/20 16:24:17 INFO Vacuumed table table=pending_objects21612026/09/20 16:24:17 INFO Vacuumed table table=multipart_uploads21622026/09/20 16:24:17 INFO Vacuumed table table=closures21632026/09/20 16:24:17 INFO Vacuumed table table=objects2164 orphaned_objects_gc_test.go:509: Stress test completed successfully:2165 orphaned_objects_gc_test.go:510: - Active objects preserved: 202166 orphaned_objects_gc_test.go:511: - Objects deleted: 2102167 orphaned_objects_gc_test.go:512: - Total GC'd: 2102168--- PASS: TestOrphanedObjectsGCStressTest (2.63s)21692026/09/20 16:24:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.710915848s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21702026/09/20 16:24:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02171=== NAME TestClientIntegration2172 client_integration_test.go:323: Objects in database after GC:2173 client_integration_test.go:323: Successfully deleted all objects with GC --force2174--- PASS: TestClientIntegration (2.69s)21752026/09/20 16:24:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02176=== NAME TestPinProtectsFromGC2177 client_integration_test.go:794: Pin successfully protected closure from garbage collection2178--- PASS: TestPinProtectsFromGC (3.02s)21792026/09/20 16:24:19 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-config21802026/09/20 16:24:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.542919ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21812026/09/20 16:24:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.926876ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21822026/09/20 16:24:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=778.940334ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21832026/09/20 16:24:20 WARN Rate limiter enabled after throttle name=s3-test rate=521842026/09/20 16:24:20 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2185=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2186 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102187 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002188--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.68s)21892026/09/20 16:24:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.498481644s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21902026/09/20 16:24:22 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"21912026/09/20 16:24:22 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_closures21922026/09/20 16:24:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.561276ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21932026/09/20 16:24:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=412.709157ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21942026/09/20 16:24:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=759.004819ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21952026/09/20 16:24:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.606519523s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2196--- PASS: TestClientErrorHandling (0.00s)2197 --- PASS: TestClientErrorHandling/InvalidStorePath (0.30s)2198 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.39s)2199 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.40s)2200PASS2201{"timestamp":"2026-09-20T16:24:25.948785363Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58468","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(391)"}22022026-09-20 16:24:26.151 UTC [131] LOG: received smart shutdown request22032026-09-20 16:24:26.156 UTC [131] LOG: background worker "logical replication launcher" (PID 141) exited with exit code 122042026-09-20 16:24:26.166 UTC [136] LOG: shutting down22052026-09-20 16:24:26.167 UTC [136] LOG: checkpoint starting: shutdown immediate22062026-09-20 16:24:26.968 UTC [136] LOG: checkpoint complete: wrote 11342 buffers (69.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 15 recycled; write=0.255 s, sync=0.518 s, total=0.803 s; sync files=18404, longest=0.063 s, average=0.001 s; distance=251187 kB, estimate=251187 kB; lsn=0/10CB2C40, redo lsn=0/10CB2C4022072026-09-20 16:24:27.041 UTC [131] LOG: database system is shut down2208Running OIDC tests...2209=== RUN TestGlobMatch2210=== PAUSE TestGlobMatch2211=== RUN TestAudienceForIssuer2212=== PAUSE TestAudienceForIssuer2213=== RUN TestValidateToken_ValidToken2214=== PAUSE TestValidateToken_ValidToken2215=== RUN TestValidateToken_WrongAudience2216=== PAUSE TestValidateToken_WrongAudience2217=== RUN TestValidateToken_Expired2218=== PAUSE TestValidateToken_Expired2219=== RUN TestValidateToken_BoundClaimsMismatch2220=== PAUSE TestValidateToken_BoundClaimsMismatch2221=== RUN TestValidateToken_BoundSubjectMismatch2222=== PAUSE TestValidateToken_BoundSubjectMismatch2223=== RUN TestValidateToken_MultipleProviders2224=== PAUSE TestValidateToken_MultipleProviders2225=== RUN TestValidateToken_NoMatchingProvider2226=== PAUSE TestValidateToken_NoMatchingProvider2227=== RUN TestValidateToken_KubernetesServiceAccount2228=== PAUSE TestValidateToken_KubernetesServiceAccount2229=== RUN TestNewValidator_KubernetesRequiresCA2230=== PAUSE TestNewValidator_KubernetesRequiresCA2231=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2232=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2233=== RUN TestScopes_LegacyProviderDefaultsToWrite2234=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2235=== RUN TestScopes_Rules2236=== PAUSE TestScopes_Rules2237=== RUN TestScopes_ConfigValidation2238=== PAUSE TestScopes_ConfigValidation2239=== CONT TestGlobMatch2240=== CONT TestValidateToken_NoMatchingProvider2241=== RUN TestGlobMatch/foo_foo2242=== CONT TestValidateToken_MultipleProviders2243=== PAUSE TestGlobMatch/foo_foo2244=== CONT TestValidateToken_BoundSubjectMismatch2245=== CONT TestValidateToken_Expired2246=== CONT TestValidateToken_WrongAudience2247=== CONT TestValidateToken_ValidToken2248=== CONT TestAudienceForIssuer2249=== CONT TestValidateToken_KubernetesServiceAccount2250=== CONT TestScopes_ConfigValidation2251=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2252=== CONT TestScopes_Rules2253=== CONT TestScopes_LegacyProviderDefaultsToWrite2254=== CONT TestNewValidator_KubernetesRequiresCA2255=== RUN TestGlobMatch/foo_bar2256=== CONT TestValidateToken_BoundClaimsMismatch2257--- PASS: TestAudienceForIssuer (0.00s)2258=== PAUSE TestGlobMatch/foo_bar2259=== RUN TestGlobMatch/*_2260=== PAUSE TestGlobMatch/*_2261=== RUN TestGlobMatch/*_anything2262=== PAUSE TestGlobMatch/*_anything2263=== RUN TestGlobMatch/foo*_foo2264=== PAUSE TestGlobMatch/foo*_foo2265=== RUN TestGlobMatch/foo*_foobar2266=== PAUSE TestGlobMatch/foo*_foobar2267=== RUN TestGlobMatch/foo*_bar2268=== PAUSE TestGlobMatch/foo*_bar2269=== RUN TestGlobMatch/*bar_bar2270=== PAUSE TestGlobMatch/*bar_bar2271=== RUN TestGlobMatch/*bar_foobar2272=== PAUSE TestGlobMatch/*bar_foobar2273=== RUN TestGlobMatch/*bar_foo2274=== PAUSE TestGlobMatch/*bar_foo2275=== RUN TestGlobMatch/foo*bar_foobar2276=== PAUSE TestGlobMatch/foo*bar_foobar2277=== RUN TestGlobMatch/foo*bar_foo123bar2278=== PAUSE TestGlobMatch/foo*bar_foo123bar2279=== RUN TestGlobMatch/foo*bar_foobarbaz2280=== PAUSE TestGlobMatch/foo*bar_foobarbaz2281=== RUN TestGlobMatch/*/*_foo/bar2282--- PASS: TestScopes_ConfigValidation (0.00s)2283=== PAUSE TestGlobMatch/*/*_foo/bar2284=== RUN TestGlobMatch/*/*_foo2285=== PAUSE TestGlobMatch/*/*_foo2286=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2287=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2288=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02289=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02290=== RUN TestGlobMatch/refs/*/main_refs/heads/main22912026/09/20 16:24:28 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232292=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2293=== RUN TestGlobMatch/fo?_foo2294=== PAUSE TestGlobMatch/fo?_foo2295=== RUN TestGlobMatch/fo?_fo2296=== PAUSE TestGlobMatch/fo?_fo2297=== RUN TestGlobMatch/fo?_fooo2298=== PAUSE TestGlobMatch/fo?_fooo2299=== RUN TestGlobMatch/?oo_foo2300=== PAUSE TestGlobMatch/?oo_foo2301=== RUN TestGlobMatch/?oo_boo2302=== PAUSE TestGlobMatch/?oo_boo2303=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2304=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2305=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2306=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2307=== CONT TestGlobMatch/foo_foo2308=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2309=== CONT TestGlobMatch/foo*bar_foobarbaz2310=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2311=== CONT TestGlobMatch/foo*bar_foo123bar2312=== CONT TestGlobMatch/?oo_boo23132026/09/20 16:24:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44525/oidc2314=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02315=== CONT TestGlobMatch/foo*_foobar2316=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2317=== CONT TestGlobMatch/*/*_foo23182026/09/20 16:24:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39743/oidc2319=== CONT TestGlobMatch/refs/*/main_refs/heads/main23202026/09/20 16:24:28 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36773/oidc2321=== CONT TestGlobMatch/?oo_foo2322=== CONT TestGlobMatch/*bar_foobar2323=== CONT TestGlobMatch/*bar_bar2324=== CONT TestGlobMatch/fo?_fooo2325=== CONT TestGlobMatch/fo?_fo2326=== CONT TestGlobMatch/*/*_foo/bar2327=== CONT TestGlobMatch/fo?_foo2328=== CONT TestGlobMatch/foo*_bar2329=== CONT TestGlobMatch/*_anything23302026/09/20 16:24:28 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42371/oidc2331=== CONT TestGlobMatch/foo*bar_foobar2332=== CONT TestGlobMatch/*bar_foo2333=== CONT TestGlobMatch/foo*_foo23342026/09/20 16:24:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39497/oidc2335=== CONT TestGlobMatch/*_2336=== CONT TestGlobMatch/foo_bar23372026/09/20 16:24:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34323/oidc2338--- PASS: TestGlobMatch (0.01s)2339 --- PASS: TestGlobMatch/foo_foo (0.00s)2340 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2341 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2342 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2343 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2344 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2345 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2346 --- PASS: TestGlobMatch/?oo_boo (0.00s)2347 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2348 --- PASS: TestGlobMatch/*/*_foo (0.00s)2349 --- PASS: TestGlobMatch/?oo_foo (0.00s)2350 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2351 --- PASS: TestGlobMatch/fo?_fo (0.00s)2352 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2353 --- PASS: TestGlobMatch/*bar_bar (0.00s)2354 --- PASS: TestGlobMatch/*_anything (0.00s)2355 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2356 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2357 --- PASS: TestGlobMatch/foo*_bar (0.00s)2358 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2359 --- PASS: TestGlobMatch/*bar_foo (0.00s)2360 --- PASS: TestGlobMatch/fo?_foo (0.00s)2361 --- PASS: TestGlobMatch/foo_bar (0.00s)2362 --- PASS: TestGlobMatch/foo*_foo (0.00s)2363 --- PASS: TestGlobMatch/*_ (0.00s)23642026/09/20 16:24:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46739/oidc23652026/09/20 16:24:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36093/oidc23662026/09/20 16:24:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39515/oidc23672026/09/20 16:24:28 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33077/oidc2368--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2369--- PASS: TestValidateToken_WrongAudience (0.01s)2370--- PASS: TestValidateToken_ValidToken (0.01s)2371--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2372--- PASS: TestValidateToken_Expired (0.02s)23732026/09/20 16:24:28 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:352812374--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2375--- PASS: TestValidateToken_MultipleProviders (0.02s)2376--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2377--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2378--- PASS: TestScopes_Rules (0.02s)23792026/09/20 16:24:28 http: TLS handshake error from 127.0.0.1:43870: remote error: tls: bad certificate2380--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2381--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2382PASS2383Running hook tests...2384=== RUN TestSendPathsEmpty2385=== PAUSE TestSendPathsEmpty2386=== RUN TestQueueEnqueueAndFetch2387=== PAUSE TestQueueEnqueueAndFetch2388=== RUN TestQueueDeduplication2389=== PAUSE TestQueueDeduplication2390=== RUN TestQueueRemove2391=== PAUSE TestQueueRemove2392=== RUN TestQueueFetchBatchLimit2393=== PAUSE TestQueueFetchBatchLimit2394=== RUN TestQueueRetryMovesToBack2395=== PAUSE TestQueueRetryMovesToBack2396=== RUN TestQueueFetchRemoveLifecycle2397=== PAUSE TestQueueFetchRemoveLifecycle2398=== RUN TestQueueConcurrentWriters2399=== PAUSE TestQueueConcurrentWriters2400=== RUN TestQueueRemoveLargeClosure2401=== PAUSE TestQueueRemoveLargeClosure2402=== RUN TestServerClientIntegration2403=== PAUSE TestServerClientIntegration2404=== RUN TestServerQueueError2405=== PAUSE TestServerQueueError2406=== RUN TestGetListenerSocketActivation2407 server_test.go:210: === RUN TestGetListenerSocketActivation2408 --- PASS: TestGetListenerSocketActivation (0.00s)2409 PASS2410 2411--- PASS: TestGetListenerSocketActivation (0.01s)2412=== RUN TestDrainIsolatesPoisonPath2413=== PAUSE TestDrainIsolatesPoisonPath2414=== RUN TestRunNotBlockedByPoisonHead2415=== PAUSE TestRunNotBlockedByPoisonHead2416=== RUN TestDrainGivesUpWhenServerDown2417=== PAUSE TestDrainGivesUpWhenServerDown2418=== RUN TestFailedPathPrunedByLaterClosure2419=== PAUSE TestFailedPathPrunedByLaterClosure2420=== RUN TestWorkerUploadsAndRemoves2421=== PAUSE TestWorkerUploadsAndRemoves2422=== RUN TestWorkerSkipsGCdPaths2423=== PAUSE TestWorkerSkipsGCdPaths2424=== RUN TestWorkerPrunesClosureDeps2425=== PAUSE TestWorkerPrunesClosureDeps2426=== RUN TestDrainTimeout2427=== PAUSE TestDrainTimeout2428=== CONT TestSendPathsEmpty2429=== CONT TestServerQueueError2430=== CONT TestQueueEnqueueAndFetch2431=== CONT TestQueueRetryMovesToBack2432--- PASS: TestSendPathsEmpty (0.00s)2433=== CONT TestQueueFetchBatchLimit2434=== CONT TestServerClientIntegration2435=== CONT TestQueueRemove2436=== CONT TestQueueRemoveLargeClosure24372026/09/20 16:24:28 ERROR Failed to queue paths error="permission denied" count=12438=== CONT TestQueueConcurrentWriters2439=== CONT TestQueueDeduplication2440=== CONT TestQueueFetchRemoveLifecycle2441=== CONT TestWorkerUploadsAndRemoves2442=== CONT TestWorkerPrunesClosureDeps2443=== CONT TestWorkerSkipsGCdPaths2444--- PASS: TestServerClientIntegration (0.00s)2445=== CONT TestDrainGivesUpWhenServerDown2446=== CONT TestDrainTimeout2447=== CONT TestFailedPathPrunedByLaterClosure2448=== CONT TestDrainIsolatesPoisonPath2449=== CONT TestRunNotBlockedByPoisonHead2450--- PASS: TestServerQueueError (0.00s)24512026/09/20 16:24:28 INFO Uploading batch count=224522026/09/20 16:24:28 INFO Uploading batch count=424532026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=424542026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=224552026/09/20 16:24:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2137166991/002/a24562026/09/20 16:24:28 INFO Upload queue status pending=324572026/09/20 16:24:28 INFO Uploading batch count=224582026/09/20 16:24:28 INFO Uploading batch count=124592026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=12460--- PASS: TestQueueEnqueueAndFetch (0.02s)24612026/09/20 16:24:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2137166991/002/b2462--- PASS: TestQueueRemove (0.02s)24632026/09/20 16:24:28 INFO Upload queue status pending=224642026/09/20 16:24:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2459988141/002/bbb24652026/09/20 16:24:28 INFO Uploading batch count=12466--- PASS: TestQueueFetchBatchLimit (0.02s)24672026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=124682026/09/20 16:24:28 INFO Upload queue status pending=224692026/09/20 16:24:28 INFO Upload queue status pending=22470--- PASS: TestQueueDeduplication (0.02s)24712026/09/20 16:24:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths944340702/002/nonexistent24722026/09/20 16:24:28 INFO Uploading batch count=124732026/09/20 16:24:28 INFO Uploading batch count=224742026/09/20 16:24:28 INFO Uploading batch count=224752026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=224762026/09/20 16:24:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2137166991/002/c24772026/09/20 16:24:28 INFO Uploading batch count=124782026/09/20 16:24:28 INFO Uploading batch count=12479--- PASS: TestQueueRetryMovesToBack (0.02s)24802026/09/20 16:24:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2137166991/002/d24812026/09/20 16:24:28 INFO Uploading batch count=12482--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24832026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=124842026/09/20 16:24:28 INFO Uploading batch count=124852026/09/20 16:24:28 INFO Uploading batch count=224862026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=224872026/09/20 16:24:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2137166991/002/e24882026/09/20 16:24:28 INFO Uploading batch count=124892026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=124902026/09/20 16:24:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2137166991/002/f24912026/09/20 16:24:28 ERROR Drain finished with paths left in queue remaining=1024922026/09/20 16:24:28 INFO Uploading batch count=124932026/09/20 16:24:28 ERROR Upload failed error="upload failed" count=124942026/09/20 16:24:28 ERROR Drain finished with paths left in queue remaining=12495--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2496--- PASS: TestDrainIsolatesPoisonPath (0.02s)2497--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2498--- PASS: TestWorkerSkipsGCdPaths (0.04s)2499--- PASS: TestWorkerPrunesClosureDeps (0.04s)2500--- PASS: TestWorkerUploadsAndRemoves (0.04s)2501--- PASS: TestQueueRemoveLargeClosure (0.11s)25022026/09/20 16:24:28 ERROR Upload failed error="context deadline exceeded" count=225032026/09/20 16:24:28 ERROR Drain finished with paths left in queue remaining=42504--- PASS: TestDrainTimeout (0.22s)2505--- PASS: TestQueueConcurrentWriters (0.28s)25062026/09/20 16:24:29 INFO Uploading batch count=125072026/09/20 16:24:29 INFO Uploading batch count=125082026/09/20 16:24:29 INFO Uploading batch count=125092026/09/20 16:24:29 ERROR Upload failed error="upload failed" count=125102026/09/20 16:24:29 INFO Uploading batch count=125112026/09/20 16:24:29 ERROR Upload failed error="upload failed" count=125122026/09/20 16:24:29 INFO Uploading batch count=125132026/09/20 16:24:29 ERROR Upload failed error="upload failed" count=125142026/09/20 16:24:29 INFO Uploading batch count=125152026/09/20 16:24:29 ERROR Upload failed error="upload failed" count=125162026/09/20 16:24:29 ERROR Drain finished with paths left in queue remaining=12517--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2518PASS